niks3-go-unit-tests
checks.aarch64-darwin.go-unit-tests
· build #141
· raw
1Running client tests...2=== RUN TestDoServerRequestAttachesToken3=== PAUSE TestDoServerRequestAttachesToken4=== RUN TestCaseHackSuffix5=== PAUSE TestCaseHackSuffix6=== RUN TestFilterOversizedClosures7=== PAUSE TestFilterOversizedClosures8=== RUN TestPartSizeForNAR9=== PAUSE TestPartSizeForNAR10=== RUN TestUploadMultipart_SupersededByPeer11=== PAUSE TestUploadMultipart_SupersededByPeer12=== RUN TestDumpPathMatchesNix13=== PAUSE TestDumpPathMatchesNix14=== RUN TestDumpPathSingleFile15=== PAUSE TestDumpPathSingleFile16=== RUN TestDumpPathWriterError17=== PAUSE TestDumpPathWriterError18=== RUN TestEncodeNixBase3219=== PAUSE TestEncodeNixBase3220=== RUN TestEncodeNixBase32WithRealHash21=== PAUSE TestEncodeNixBase32WithRealHash22=== RUN TestConvertHashToNix3223=== PAUSE TestConvertHashToNix3224=== RUN TestGetStorePathHash25=== PAUSE TestGetStorePathHash26=== RUN TestPathInfoHashCompatibility27=== PAUSE TestPathInfoHashCompatibility28=== RUN TestParsePathInfoJSON29=== PAUSE TestParsePathInfoJSON30=== RUN TestParsePathInfoJSONMultiplePaths31=== PAUSE TestParsePathInfoJSONMultiplePaths32=== RUN TestPathInfoCACompatibility33=== PAUSE TestPathInfoCACompatibility34=== RUN TestRateLimiterFeedback35=== PAUSE TestRateLimiterFeedback36=== RUN TestRateLimiterFeedback_400DoesNotCountAsSuccess37=== PAUSE TestRateLimiterFeedback_400DoesNotCountAsSuccess38=== RUN TestResolveStorePath39=== PAUSE TestResolveStorePath40=== RUN TestDoWithRetry_BodyReplayedViaGetBody41=== PAUSE TestDoWithRetry_BodyReplayedViaGetBody42=== RUN TestShellSplit43=== PAUSE TestShellSplit44=== RUN TestShellSplitErrors45=== PAUSE TestShellSplitErrors46=== RUN TestSetClientTLS47=== PAUSE TestSetClientTLS48=== RUN TestSetClientTLSDoesNotMutateDefaultTransport49=== PAUSE TestSetClientTLSDoesNotMutateDefaultTransport50=== RUN TestSetClientTLSErrors51=== PAUSE TestSetClientTLSErrors52=== RUN TestStaticToken53=== PAUSE TestStaticToken54=== RUN TestFileTokenReadsAndCaches55=== PAUSE TestFileTokenReadsAndCaches56=== RUN TestFileTokenMissing57=== PAUSE TestFileTokenMissing58=== RUN TestFileTokenEmpty59=== PAUSE TestFileTokenEmpty60=== RUN TestScriptTokenNoExpiryRerunsEveryCall61=== PAUSE TestScriptTokenNoExpiryRerunsEveryCall62=== RUN TestScriptTokenCachesUntilRefresh63=== PAUSE TestScriptTokenCachesUntilRefresh64=== RUN TestScriptTokenEmptyToken65=== PAUSE TestScriptTokenEmptyToken66=== RUN TestScriptTokenBadJSON67=== PAUSE TestScriptTokenBadJSON68=== RUN TestScriptTokenScriptFails69=== PAUSE TestScriptTokenScriptFails70=== RUN TestScriptTokenEmptyCommand71=== PAUSE TestScriptTokenEmptyCommand72=== CONT TestDoServerRequestAttachesToken73=== CONT TestFileTokenMissing74=== CONT TestResolveStorePath75=== CONT TestEncodeNixBase32WithRealHash76--- PASS: TestEncodeNixBase32WithRealHash (0.00s)77=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess78=== CONT TestDumpPathMatchesNix79=== CONT TestSetClientTLSDoesNotMutateDefaultTransport80=== CONT TestDumpPathWriterError81=== CONT TestParsePathInfoJSON82=== RUN TestParsePathInfoJSON/Nix_format83=== PAUSE TestParsePathInfoJSON/Nix_format84=== RUN TestParsePathInfoJSON/Lix_format85=== PAUSE TestParsePathInfoJSON/Lix_format86=== RUN TestParsePathInfoJSON/empty_input87=== PAUSE TestParsePathInfoJSON/empty_input88=== RUN TestParsePathInfoJSON/whitespace_only89=== PAUSE TestParsePathInfoJSON/whitespace_only90=== RUN TestParsePathInfoJSON/invalid_JSON91=== PAUSE TestParsePathInfoJSON/invalid_JSON92=== CONT TestParsePathInfoJSON/Nix_format932026/08/27 09:28:10 WARN Rate limiter enabled after throttle name=server-test rate=594--- PASS: TestFileTokenMissing (0.00s)95=== CONT TestScriptTokenEmptyCommand96--- PASS: TestScriptTokenEmptyCommand (0.00s)97=== CONT TestScriptTokenScriptFails98=== CONT TestShellSplitErrors99--- PASS: TestShellSplitErrors (0.00s)100=== CONT TestScriptTokenCachesUntilRefresh101=== CONT TestEncodeNixBase32102=== RUN TestEncodeNixBase32/test_string_hash103=== PAUSE TestEncodeNixBase32/test_string_hash104=== RUN TestEncodeNixBase32/empty_input105=== PAUSE TestEncodeNixBase32/empty_input106=== CONT TestScriptTokenBadJSON107=== CONT TestScriptTokenEmptyToken108--- PASS: TestDoServerRequestAttachesToken (0.01s)109=== CONT TestGetStorePathHash110=== RUN TestGetStorePathHash/valid_store_path111=== PAUSE TestGetStorePathHash/valid_store_path112=== RUN TestGetStorePathHash/basename_without_hyphen_should_error113=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error114=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error115=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error116=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error117=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error118=== CONT TestPathInfoHashCompatibility119=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)120=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)121=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon122=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon123=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI124=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI125=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512126=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512127=== CONT TestStaticToken128--- PASS: TestStaticToken (0.00s)129=== CONT TestFileTokenReadsAndCaches130--- PASS: TestResolveStorePath (0.01s)131=== CONT TestFilterOversizedClosures132=== RUN TestFilterOversizedClosures/no_limit_keeps_everything133=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything134=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped135=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped136=== RUN TestFilterOversizedClosures/all_closures_skipped137=== PAUSE TestFilterOversizedClosures/all_closures_skipped138=== CONT TestUploadMultipart_SupersededByPeer139=== RUN TestUploadMultipart_SupersededByPeer/exists140=== PAUSE TestUploadMultipart_SupersededByPeer/exists141=== RUN TestUploadMultipart_SupersededByPeer/missing142=== PAUSE TestUploadMultipart_SupersededByPeer/missing143=== CONT TestPartSizeForNAR144=== RUN TestPartSizeForNAR/zero_stays_at_minimum145=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum146=== RUN TestPartSizeForNAR/small_stays_at_minimum147=== PAUSE TestPartSizeForNAR/small_stays_at_minimum148=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum149=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum150=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts151=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts152=== RUN TestPartSizeForNAR/1_TiB153=== PAUSE TestPartSizeForNAR/1_TiB154=== RUN TestPartSizeForNAR/5_TiB_S3_max_object155=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object156=== RUN TestPartSizeForNAR/capped_at_5_GiB157=== PAUSE TestPartSizeForNAR/capped_at_5_GiB158=== CONT TestScriptTokenNoExpiryRerunsEveryCall159--- PASS: TestScriptTokenScriptFails (0.01s)160=== CONT TestFileTokenEmpty161--- PASS: TestFileTokenReadsAndCaches (0.00s)162=== CONT TestShellSplit163--- PASS: TestShellSplit (0.00s)164=== CONT TestConvertHashToNix32165=== RUN TestConvertHashToNix32/SRI_format_to_Nix32166=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32167=== RUN TestConvertHashToNix32/already_Nix32_format168=== PAUSE TestConvertHashToNix32/already_Nix32_format169=== RUN TestConvertHashToNix32/invalid_format170=== PAUSE TestConvertHashToNix32/invalid_format171=== CONT TestSetClientTLS172--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.01s)173=== CONT TestDoWithRetry_BodyReplayedViaGetBody174--- PASS: TestFileTokenEmpty (0.00s)175=== CONT TestParsePathInfoJSON/invalid_JSON176=== CONT TestRateLimiterFeedback177=== RUN TestRateLimiterFeedback/429_enables_limiter178=== PAUSE TestRateLimiterFeedback/429_enables_limiter179=== RUN TestRateLimiterFeedback/503_enables_limiter180=== PAUSE TestRateLimiterFeedback/503_enables_limiter181=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter182=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter183=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter184=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter185=== CONT TestPathInfoCACompatibility186=== RUN TestPathInfoCACompatibility/null_ca_field187=== PAUSE TestPathInfoCACompatibility/null_ca_field188=== RUN TestPathInfoCACompatibility/old_string_format_-_text189=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text190=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive191=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive192=== RUN TestPathInfoCACompatibility/new_structured_format_-_text193=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text194=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method1952026/08/27 09:28:10 WARN Rate limiter enabled after throttle name=server-test rate=5196=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method197=== CONT TestParsePathInfoJSONMultiplePaths1982026/08/27 09:28:10 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:50579199=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths200=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths201=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths202=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths203=== CONT TestCaseHackSuffix2042026/08/27 09:28:10 WARN Rate limiter backed off name=server-test rate=52052026/08/27 09:28:10 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:50579206--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.00s)207=== CONT TestParsePathInfoJSON/empty_input208=== CONT TestParsePathInfoJSON/whitespace_only209=== CONT TestDumpPathSingleFile210=== RUN TestSetClientTLS/rejects_connection_without_client_cert211=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert212=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA213=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA214=== RUN TestSetClientTLS/preserves_debug_logging_transport215=== PAUSE TestSetClientTLS/preserves_debug_logging_transport216=== CONT TestSetClientTLSErrors217--- PASS: TestScriptTokenEmptyToken (0.02s)218=== CONT TestParsePathInfoJSON/Lix_format219--- PASS: TestParsePathInfoJSON (0.00s)220 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)221 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)222 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)223 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)224 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)225=== CONT TestEncodeNixBase32/test_string_hash226=== CONT TestEncodeNixBase32/empty_input227--- PASS: TestEncodeNixBase32 (0.00s)228 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)229 --- PASS: TestEncodeNixBase32/empty_input (0.00s)230=== CONT TestGetStorePathHash/valid_store_path231=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error232=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error233=== CONT TestGetStorePathHash/basename_without_hyphen_should_error234--- PASS: TestGetStorePathHash (0.00s)235 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)236 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)237 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)238 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)239=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)240=== RUN TestSetClientTLSErrors/missing_cert_file241=== PAUSE TestSetClientTLSErrors/missing_cert_file242=== RUN TestSetClientTLSErrors/missing_key_file243=== PAUSE TestSetClientTLSErrors/missing_key_file244=== RUN TestSetClientTLSErrors/missing_ca_file245=== PAUSE TestSetClientTLSErrors/missing_ca_file246=== RUN TestSetClientTLSErrors/invalid_ca_file247=== PAUSE TestSetClientTLSErrors/invalid_ca_file248=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI249=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon250=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512251--- PASS: TestPathInfoHashCompatibility (0.00s)252 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)253 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)254 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)255 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)256=== CONT TestFilterOversizedClosures/no_limit_keeps_everything257=== CONT TestUploadMultipart_SupersededByPeer/exists258=== CONT TestFilterOversizedClosures/all_closures_skipped2592026/08/27 09:28:10 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=50260=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped2612026/08/27 09:28:10 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=2000262--- PASS: TestFilterOversizedClosures (0.00s)263 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)264 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)265 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)266=== CONT TestPartSizeForNAR/zero_stays_at_minimum267=== CONT TestUploadMultipart_SupersededByPeer/missing268--- PASS: TestScriptTokenBadJSON (0.02s)269=== CONT TestPartSizeForNAR/1_TiB270=== CONT TestPartSizeForNAR/capped_at_5_GiB271=== CONT TestPartSizeForNAR/5_TiB_S3_max_object272=== CONT TestPartSizeForNAR/small_stays_at_minimum273=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts274=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum275--- PASS: TestPartSizeForNAR (0.00s)276 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)277 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)278 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)279 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)280 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)281 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)282 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)283=== CONT TestConvertHashToNix32/SRI_format_to_Nix32284=== CONT TestConvertHashToNix32/invalid_format285=== CONT TestConvertHashToNix32/already_Nix32_format286--- PASS: TestConvertHashToNix32 (0.00s)287 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)288 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)289 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)290=== CONT TestRateLimiterFeedback/429_enables_limiter291=== CONT TestPathInfoCACompatibility/null_ca_field292=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter2932026/08/27 09:28:10 WARN Rate limiter enabled after throttle name=server-test rate=52942026/08/27 09:28:10 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:50585295=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter2962026/08/27 09:28:10 WARN Rate limiter backed off name=server-test rate=5297=== CONT TestRateLimiterFeedback/503_enables_limiter298=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method2992026/08/27 09:28:10 WARN Rate limiter enabled after throttle name=server-test rate=53002026/08/27 09:28:10 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:50592301--- PASS: TestUploadMultipart_SupersededByPeer (0.00s)302 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)303 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)304=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths305=== CONT TestPathInfoCACompatibility/new_structured_format_-_text306=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive307=== CONT TestPathInfoCACompatibility/old_string_format_-_text308=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths309--- PASS: TestPathInfoCACompatibility (0.00s)310 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)311 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)312 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)313 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)314 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)315=== CONT TestSetClientTLS/rejects_connection_without_client_cert316--- PASS: TestParsePathInfoJSONMultiplePaths (0.00s)317 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)318 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)319=== CONT TestSetClientTLS/preserves_debug_logging_transport3202026/08/27 09:28:10 WARN Rate limiter backed off name=server-test rate=5321--- PASS: TestRateLimiterFeedback (0.00s)322 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)323 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)324 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)325 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)326=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA327=== CONT TestSetClientTLSErrors/missing_cert_file328=== CONT TestSetClientTLSErrors/missing_ca_file329=== CONT TestSetClientTLSErrors/invalid_ca_file330=== CONT TestSetClientTLSErrors/missing_key_file331--- PASS: TestSetClientTLSErrors (0.00s)332 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)333 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)334 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)335 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)3362026/08/27 09:28:10 http: TLS handshake error from 127.0.0.1:50595: read tcp 127.0.0.1:50581->127.0.0.1:50595: use of closed network connection337--- PASS: TestSetClientTLS (0.01s)338 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.00s)339 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.00s)340 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.01s)341--- PASS: TestScriptTokenCachesUntilRefresh (0.04s)342--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.04s)343--- PASS: TestDumpPathWriterError (0.06s)344--- PASS: TestDumpPathSingleFile (0.05s)345--- PASS: TestCaseHackSuffix (0.05s)346--- PASS: TestDumpPathMatchesNix (0.08s)347--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)348PASS349Running server tests...350The files belonging to this database system will be owned by user "_nixbld1".351This user must also own the server process.352353The database cluster will be initialized with locale "C".354The default database encoding has accordingly been set to "SQL_ASCII".355The default text search configuration will be set to "english".356357Data page checksums are enabled.358359creating directory /nix/var/nix/builds/nix-13638-4044143606/postgres100756022/data ... ok360creating subdirectories ... ok361selecting dynamic shared memory implementation ... posix362selecting default "max_connections" ... 100363selecting default "shared_buffers" ... 128MB364selecting default time zone ... UTC365creating configuration files ... ok366running bootstrap script ... ok367performing post-bootstrap initialization ... ok368syncing data to disk ... ok369370initdb: warning: enabling "trust" authentication for local connections371initdb: hint: You can change this by editing pg_hba.conf or using the option -A, or --auth-local and --auth-host, the next time you run initdb.372373Success. You can now start the database server using:374375 pg_ctl -D /nix/var/nix/builds/nix-13638-4044143606/postgres100756022/data -l logfile start376377/nix/var/nix/builds/nix-13638-4044143606/postgres100756022:5432 - no response3782026-08-27 09:28:12.400 UTC [13673] LOG: starting PostgreSQL 18.4 on aarch64-apple-darwin25.5.0, compiled by clang version 21.1.8, 64-bit3792026-08-27 09:28:12.401 UTC [13673] LOG: listening on Unix socket "/nix/var/nix/builds/nix-13638-4044143606/postgres100756022/.s.PGSQL.5432"3802026-08-27 09:28:12.403 UTC [13680] LOG: database system was shut down at 2026-08-27 09:28:12 UTC3812026-08-27 09:28:12.403 UTC [13673] LOG: database system is ready to accept connections382/nix/var/nix/builds/nix-13638-4044143606/postgres100756022:5432 - accepting connections383=== RUN TestService_AuthMiddleware384=== PAUSE TestService_AuthMiddleware385=== RUN TestService_AuthMiddleware_MTLSProxyHeader386=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader387=== RUN TestService_AuthMiddleware_MTLSBoundSubjects388=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects389=== RUN TestService_ReadAuthMiddleware390=== PAUSE TestService_ReadAuthMiddleware391=== RUN TestService_AuthMiddleware_OIDC392=== PAUSE TestService_AuthMiddleware_OIDC393=== RUN TestCacheConfigHandler394=== PAUSE TestCacheConfigHandler395=== RUN TestCacheStatsHandler396=== PAUSE TestCacheStatsHandler397=== RUN TestClientCADerivations398=== PAUSE TestClientCADerivations399=== RUN TestClientErrorHandling400=== PAUSE TestClientErrorHandling401=== RUN TestClientIntegration402=== PAUSE TestClientIntegration403=== RUN TestClientMultipleUploads404=== PAUSE TestClientMultipleUploads405=== RUN TestClientWithDependencies406=== PAUSE TestClientWithDependencies407=== RUN TestPinProtectsFromGC408=== PAUSE TestPinProtectsFromGC409=== RUN TestGCAdvisoryLockBlocksConcurrentRun4102026-08-27 09:28:12.663 UTC [13752] ERROR: relation "goose_db_version" does not exist at character 364112026-08-27 09:28:12.663 UTC [13752] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC4122026/08/27 09:28:12 OK 20241026095416_initial_model.sql (3.13ms)4132026/08/27 09:28:12 OK 20251210153512_drop_unused_gin_index.sql (536.21µs)4142026/08/27 09:28:12 OK 20251218171726_add_pins.sql (767µs)4152026/08/27 09:28:12 OK 20260628120000_add_object_size_and_stats.sql (759.88µs)4162026/08/27 09:28:12 goose: successfully migrated database to version: 202606281200004172026/08/27 09:28:12 OK 1_commit_pending_closure.sql (774.79µs)4182026/08/27 09:28:12 OK 2_object_stats_trigger.sql (228.83µs)4192026/08/27 09:28:12 goose: up to current file version: 2420--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.09s)421=== RUN TestGCBugBareHashReferences422=== PAUSE TestGCBugBareHashReferences423=== RUN TestGCMetrics424=== PAUSE TestGCMetrics425=== RUN TestGCTaskStore_StartNew426=== PAUSE TestGCTaskStore_StartNew427=== RUN TestGCTaskStore_DeduplicateSameParams428=== PAUSE TestGCTaskStore_DeduplicateSameParams429=== RUN TestGCTaskStore_ConflictDifferentParams430=== PAUSE TestGCTaskStore_ConflictDifferentParams431=== RUN TestGCTaskStore_GetEmpty432=== PAUSE TestGCTaskStore_GetEmpty433=== RUN TestGCTaskStore_GetReturnsLatest434=== PAUSE TestGCTaskStore_GetReturnsLatest435=== RUN TestGCTaskStore_CompletedAllowsNewTask436=== PAUSE TestGCTaskStore_CompletedAllowsNewTask437=== RUN TestGCTaskStore_PhaseUpdates438=== PAUSE TestGCTaskStore_PhaseUpdates439=== RUN TestGCTaskStore_Fail440=== PAUSE TestGCTaskStore_Fail441=== RUN TestGracefulShutdownDrainsInflight442=== PAUSE TestGracefulShutdownDrainsInflight443=== RUN TestService_healthCheckHandler444=== PAUSE TestService_healthCheckHandler445=== RUN TestGenerateLandingPage446=== PAUSE TestGenerateLandingPage447=== RUN TestCacheConfigHandlerMaxNarSize448=== PAUSE TestCacheConfigHandlerMaxNarSize449=== RUN TestCreatePendingClosureRejectsOversizedNAR450=== PAUSE TestCreatePendingClosureRejectsOversizedNAR451=== RUN TestNARDeduplicationMetadataUploadBug452=== PAUSE TestNARDeduplicationMetadataUploadBug453=== RUN TestMetricsInventory454=== PAUSE TestMetricsInventory455=== RUN TestService_NativeMTLS456=== PAUSE TestService_NativeMTLS457=== RUN TestServerTLSConfig458=== PAUSE TestServerTLSConfig459=== RUN TestMultipartCleanup460=== PAUSE TestMultipartCleanup461=== RUN TestObjectStatsTrigger462=== PAUSE TestObjectStatsTrigger463=== RUN TestOrphanedObjectsGC464=== PAUSE TestOrphanedObjectsGC465=== RUN TestOrphanedObjectsGCStressTest466=== PAUSE TestOrphanedObjectsGCStressTest467=== RUN TestResurrectedObjectNotDeleted468=== PAUSE TestResurrectedObjectNotDeleted469=== RUN TestParseSingleRange470=== PAUSE TestParseSingleRange471=== RUN TestIsValidCachePath472=== PAUSE TestIsValidCachePath473=== RUN TestReadProxyNarinfo474=== PAUSE TestReadProxyNarinfo475=== RUN TestReadProxyNarinfoAlreadyDecompressed476=== PAUSE TestReadProxyNarinfoAlreadyDecompressed477=== RUN TestReadProxyNarStreaming478=== PAUSE TestReadProxyNarStreaming479=== RUN TestReadProxy404480=== PAUSE TestReadProxy404481=== RUN TestReadProxyInvalidPath482=== PAUSE TestReadProxyInvalidPath483=== RUN TestReadProxyHead484=== PAUSE TestReadProxyHead485=== RUN TestReadProxyConditionalGet486=== PAUSE TestReadProxyConditionalGet487=== RUN TestReadProxyRootRedirectsToIndexHTML488=== PAUSE TestReadProxyRootRedirectsToIndexHTML489=== RUN TestReadProxyDisabled490=== PAUSE TestReadProxyDisabled491=== RUN TestReadProxyRangeRequest492=== PAUSE TestReadProxyRangeRequest493=== RUN TestRedundantMultipartUpload494=== PAUSE TestRedundantMultipartUpload495=== RUN TestCompleteMultipartUpload_ErrorButObjectExists496=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists497=== RUN TestCompletedNarNotReofferedAcrossClosures498=== PAUSE TestCompletedNarNotReofferedAcrossClosures499=== RUN TestPresignedUploadRegisteredBeforeCommit500=== PAUSE TestPresignedUploadRegisteredBeforeCommit501=== RUN TestService_Rustfstest502=== PAUSE TestService_Rustfstest503=== RUN TestParseSize504=== PAUSE TestParseSize505=== RUN TestSkippedUploadsHandler506=== PAUSE TestSkippedUploadsHandler507=== RUN TestSystemdListenerNotActivated508--- PASS: TestSystemdListenerNotActivated (0.00s)509=== RUN TestWatchdogBeatsWhenHealthy510--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)511=== RUN TestWatchdogSkipsWhenUnhealthy5122026/08/27 09:28:12 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5132026/08/27 09:28:12 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5142026/08/27 09:28:12 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5152026/08/27 09:28:12 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5162026/08/27 09:28:12 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5172026/08/27 09:28:12 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5182026/08/27 09:28:12 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5192026/08/27 09:28:12 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5202026/08/27 09:28:12 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"521--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)522=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle523=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle524=== RUN TestProxyWriteTimeout525=== PAUSE TestProxyWriteTimeout526=== RUN TestIsValidUploadKey527=== PAUSE TestIsValidUploadKey528=== RUN TestUploadHandlersRejectInvalidKeys529=== PAUSE TestUploadHandlersRejectInvalidKeys530=== RUN TestUploadHandlersRejectOversizedBody531=== PAUSE TestUploadHandlersRejectOversizedBody532=== RUN TestService_cleanupPendingClosuresHandler533=== PAUSE TestService_cleanupPendingClosuresHandler534=== RUN TestService_createPendingClosureHandler535=== PAUSE TestService_createPendingClosureHandler536=== RUN TestService_verifyS3Integrity537=== PAUSE TestService_verifyS3Integrity538=== RUN TestCompleteMultipartUnregistered539=== PAUSE TestCompleteMultipartUnregistered540=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT541=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT542=== CONT TestCompleteMultipartUnregistered543=== CONT TestService_AuthMiddleware544=== CONT TestService_verifyS3Integrity545=== CONT TestService_createPendingClosureHandler546=== CONT TestService_cleanupPendingClosuresHandler547=== CONT TestUploadHandlersRejectOversizedBody548=== CONT TestUploadHandlersRejectInvalidKeys549=== CONT TestIsValidUploadKey550=== CONT TestProxyWriteTimeout551=== RUN TestProxyWriteTimeout/narinfo552=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info553=== RUN TestIsValidUploadKey/narinfo554=== PAUSE TestProxyWriteTimeout/narinfo555=== RUN TestProxyWriteTimeout/1_GiB_nar556=== PAUSE TestProxyWriteTimeout/1_GiB_nar557=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle558=== PAUSE TestIsValidUploadKey/narinfo559=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info560=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal561=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal562=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key563=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key564=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key565=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key566=== RUN TestIsValidUploadKey/nar_zst567=== RUN TestProxyWriteTimeout/10_GiB_nar568=== PAUSE TestIsValidUploadKey/nar_zst569=== RUN TestIsValidUploadKey/nar_xz570=== CONT TestSkippedUploadsHandler571=== PAUSE TestProxyWriteTimeout/10_GiB_nar572=== RUN TestProxyWriteTimeout/unknown_size573=== PAUSE TestIsValidUploadKey/nar_xz574=== RUN TestIsValidUploadKey/nar_plain575=== PAUSE TestIsValidUploadKey/nar_plain576=== RUN TestIsValidUploadKey/listing577=== PAUSE TestIsValidUploadKey/listing578=== RUN TestIsValidUploadKey/build_log579=== PAUSE TestIsValidUploadKey/build_log580=== RUN TestIsValidUploadKey/build_log_home-manager_file581=== PAUSE TestIsValidUploadKey/build_log_home-manager_file582=== RUN TestIsValidUploadKey/build_log_plus_in_name583=== PAUSE TestIsValidUploadKey/build_log_plus_in_name584=== RUN TestIsValidUploadKey/build_log_question_mark585=== PAUSE TestIsValidUploadKey/build_log_question_mark586=== RUN TestIsValidUploadKey/build_log_equals587=== PAUSE TestIsValidUploadKey/build_log_equals588=== RUN TestIsValidUploadKey/realisation589=== PAUSE TestIsValidUploadKey/realisation590=== RUN TestIsValidUploadKey/realisation_plus_in_output591=== PAUSE TestIsValidUploadKey/realisation_plus_in_output592=== RUN TestIsValidUploadKey/nix-cache-info593=== PAUSE TestIsValidUploadKey/nix-cache-info594=== RUN TestIsValidUploadKey/index.html595=== PAUSE TestIsValidUploadKey/index.html596=== RUN TestIsValidUploadKey/narinfo_key,_nar_type597=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type598=== RUN TestIsValidUploadKey/nar_key,_narinfo_type599=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type600=== RUN TestIsValidUploadKey/listing_key,_narinfo_type601=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type602=== PAUSE TestProxyWriteTimeout/unknown_size603=== RUN TestIsValidUploadKey/traversal604=== CONT TestParseSize605--- PASS: TestParseSize (0.00s)606=== CONT TestService_Rustfstest607=== PAUSE TestIsValidUploadKey/traversal608=== RUN TestIsValidUploadKey/traversal_nar609=== PAUSE TestIsValidUploadKey/traversal_nar610=== RUN TestIsValidUploadKey/absolute611=== PAUSE TestIsValidUploadKey/absolute6122026/08/27 09:28:12 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000613=== RUN TestIsValidUploadKey/empty_key614=== PAUSE TestIsValidUploadKey/empty_key615=== RUN TestIsValidUploadKey/unknown_type616=== PAUSE TestIsValidUploadKey/unknown_type617=== CONT TestPresignedUploadRegisteredBeforeCommit618--- PASS: TestSkippedUploadsHandler (0.00s)619=== CONT TestCompletedNarNotReofferedAcrossClosures620=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure621=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure622=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart623=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart624=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts625=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts626=== CONT TestCompleteMultipartUpload_ErrorButObjectExists6272026-08-27 09:28:13.213 UTC [13774] ERROR: relation "goose_db_version" does not exist at character 366282026-08-27 09:28:13.213 UTC [13774] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6292026-08-27 09:28:13.214 UTC [13775] ERROR: relation "goose_db_version" does not exist at character 366302026-08-27 09:28:13.214 UTC [13775] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6312026-08-27 09:28:13.217 UTC [13776] ERROR: relation "goose_db_version" does not exist at character 366322026-08-27 09:28:13.217 UTC [13776] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6332026-08-27 09:28:13.219 UTC [13777] ERROR: relation "goose_db_version" does not exist at character 366342026-08-27 09:28:13.219 UTC [13777] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6352026-08-27 09:28:13.222 UTC [13778] ERROR: relation "goose_db_version" does not exist at character 366362026-08-27 09:28:13.222 UTC [13778] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6372026-08-27 09:28:13.222 UTC [13779] ERROR: relation "goose_db_version" does not exist at character 366382026-08-27 09:28:13.222 UTC [13779] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6392026-08-27 09:28:13.227 UTC [13780] ERROR: relation "goose_db_version" does not exist at character 366402026-08-27 09:28:13.227 UTC [13780] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6412026-08-27 09:28:13.228 UTC [13781] ERROR: relation "goose_db_version" does not exist at character 366422026-08-27 09:28:13.228 UTC [13781] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6432026/08/27 09:28:13 OK 20241026095416_initial_model.sql (8.06ms)6442026-08-27 09:28:13.228 UTC [13782] ERROR: relation "goose_db_version" does not exist at character 366452026-08-27 09:28:13.228 UTC [13782] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6462026/08/27 09:28:13 OK 20241026095416_initial_model.sql (8.64ms)6472026/08/27 09:28:13 OK 20251210153512_drop_unused_gin_index.sql (700.46µs)6482026/08/27 09:28:13 OK 20251210153512_drop_unused_gin_index.sql (781.63µs)6492026/08/27 09:28:13 OK 20251218171726_add_pins.sql (2.19ms)6502026-08-27 09:28:13.231 UTC [13783] ERROR: relation "goose_db_version" does not exist at character 366512026-08-27 09:28:13.231 UTC [13783] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6522026/08/27 09:28:13 OK 20241026095416_initial_model.sql (6.45ms)6532026/08/27 09:28:13 OK 20251218171726_add_pins.sql (2.5ms)6542026/08/27 09:28:13 OK 20241026095416_initial_model.sql (7.91ms)6552026/08/27 09:28:13 OK 20251210153512_drop_unused_gin_index.sql (917.54µs)6562026/08/27 09:28:13 OK 20260628120000_add_object_size_and_stats.sql (1.86ms)6572026/08/27 09:28:13 goose: successfully migrated database to version: 202606281200006582026/08/27 09:28:13 OK 20251210153512_drop_unused_gin_index.sql (902.21µs)6592026/08/27 09:28:13 OK 20260628120000_add_object_size_and_stats.sql (1.71ms)6602026/08/27 09:28:13 goose: successfully migrated database to version: 202606281200006612026/08/27 09:28:13 OK 20251218171726_add_pins.sql (1.29ms)6622026/08/27 09:28:13 OK 1_commit_pending_closure.sql (1.5ms)6632026/08/27 09:28:13 OK 1_commit_pending_closure.sql (1.33ms)6642026/08/27 09:28:13 OK 2_object_stats_trigger.sql (497µs)6652026/08/27 09:28:13 goose: up to current file version: 26662026/08/27 09:28:13 OK 20241026095416_initial_model.sql (8.49ms)6672026/08/27 09:28:13 OK 20251218171726_add_pins.sql (1.89ms)6682026/08/27 09:28:13 OK 2_object_stats_trigger.sql (553.79µs)6692026/08/27 09:28:13 goose: up to current file version: 26702026/08/27 09:28:13 OK 20260628120000_add_object_size_and_stats.sql (1.55ms)6712026/08/27 09:28:13 goose: successfully migrated database to version: 202606281200006722026/08/27 09:28:13 OK 20241026095416_initial_model.sql (8.81ms)6732026/08/27 09:28:13 OK 20251210153512_drop_unused_gin_index.sql (628.88µs)6742026/08/27 09:28:13 OK 20260628120000_add_object_size_and_stats.sql (1.1ms)6752026/08/27 09:28:13 goose: successfully migrated database to version: 202606281200006762026/08/27 09:28:13 OK 20251210153512_drop_unused_gin_index.sql (999.04µs)6772026/08/27 09:28:13 OK 20241026095416_initial_model.sql (5.28ms)6782026/08/27 09:28:13 OK 20251218171726_add_pins.sql (1.41ms)6792026/08/27 09:28:13 OK 20241026095416_initial_model.sql (6.15ms)6802026/08/27 09:28:13 OK 1_commit_pending_closure.sql (875.25µs)6812026/08/27 09:28:13 OK 1_commit_pending_closure.sql (1.99ms)6822026/08/27 09:28:13 OK 2_object_stats_trigger.sql (304.29µs)6832026/08/27 09:28:13 goose: up to current file version: 26842026/08/27 09:28:13 OK 2_object_stats_trigger.sql (406.58µs)6852026/08/27 09:28:13 goose: up to current file version: 26862026/08/27 09:28:13 OK 20251210153512_drop_unused_gin_index.sql (4.3ms)6872026/08/27 09:28:13 OK 20251218171726_add_pins.sql (5.45ms)6882026/08/27 09:28:13 OK 20251210153512_drop_unused_gin_index.sql (4.63ms)6892026/08/27 09:28:13 OK 20241026095416_initial_model.sql (11.73ms)6902026/08/27 09:28:13 OK 20260628120000_add_object_size_and_stats.sql (5.7ms)6912026/08/27 09:28:13 goose: successfully migrated database to version: 202606281200006922026/08/27 09:28:13 OK 20251218171726_add_pins.sql (1.12ms)6932026/08/27 09:28:13 OK 20251218171726_add_pins.sql (1.05ms)6942026/08/27 09:28:13 OK 1_commit_pending_closure.sql (854.63µs)6952026/08/27 09:28:13 OK 2_object_stats_trigger.sql (207µs)6962026/08/27 09:28:13 goose: up to current file version: 26972026/08/27 09:28:13 OK 20251210153512_drop_unused_gin_index.sql (75.65ms)6982026/08/27 09:28:13 OK 20260628120000_add_object_size_and_stats.sql (76.64ms)6992026/08/27 09:28:13 goose: successfully migrated database to version: 202606281200007002026/08/27 09:28:13 OK 1_commit_pending_closure.sql (1.72ms)7012026/08/27 09:28:13 OK 2_object_stats_trigger.sql (245.92µs)7022026/08/27 09:28:13 goose: up to current file version: 27032026/08/27 09:28:13 OK 20260628120000_add_object_size_and_stats.sql (83.12ms)7042026/08/27 09:28:13 goose: successfully migrated database to version: 202606281200007052026/08/27 09:28:13 OK 20260628120000_add_object_size_and_stats.sql (83.09ms)7062026/08/27 09:28:13 goose: successfully migrated database to version: 202606281200007072026/08/27 09:28:13 OK 1_commit_pending_closure.sql (1.04ms)7082026/08/27 09:28:13 OK 1_commit_pending_closure.sql (1.19ms)7092026/08/27 09:28:13 OK 2_object_stats_trigger.sql (221.46µs)7102026/08/27 09:28:13 goose: up to current file version: 27112026/08/27 09:28:13 OK 2_object_stats_trigger.sql (219.46µs)7122026/08/27 09:28:13 goose: up to current file version: 27132026/08/27 09:28:13 OK 20251218171726_add_pins.sql (14.11ms)7142026/08/27 09:28:13 OK 20241026095416_initial_model.sql (97.45ms)7152026/08/27 09:28:13 OK 20251210153512_drop_unused_gin_index.sql (2.15ms)7162026/08/27 09:28:13 OK 20260628120000_add_object_size_and_stats.sql (5.98ms)7172026/08/27 09:28:13 goose: successfully migrated database to version: 202606281200007182026/08/27 09:28:13 OK 20251218171726_add_pins.sql (4.53ms)7192026/08/27 09:28:13 OK 1_commit_pending_closure.sql (1.42ms)7202026/08/27 09:28:13 OK 2_object_stats_trigger.sql (208.21µs)7212026/08/27 09:28:13 goose: up to current file version: 2722{"timestamp":"2026-08-27T09:28:13.341017Z","level":"ERROR","duration":"98.833µs","resp":"Response { status: 503, version: HTTP/1.1, headers: {\"content-type\": \"application/xml\"}, body: Body { once: b\"<?xml version=\\\"1.0\\\" encoding=\\\"UTF-8\\\"?><Error><Code>SlowDown</Code><Message>bucket creation concurrency limit reached; retry later</Message></Error>\" } }","target":"s3s::service","filename":"/nix/var/nix/builds/nix-57705-2947227838/rustfs-1.0.0-beta.12-vendor/source-git-1/s3s-0.14.1/src/service.rs","line_number":640,"threadName":"rustfs-worker","threadId":"ThreadId(9)"}723{"timestamp":"2026-08-27T09:28:13.341083Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"8cee6d92-eef8-403c-b93e-82701a611d6e","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"PUT","uri":"/bucket10/","status_code":503,"duration_ms":0,"result":"server_error","target":"rustfs::server::layer","filename":"rustfs/src/server/layer.rs","line_number":392,"threadName":"rustfs-worker","threadId":"ThreadId(9)"}7242026/08/27 09:28:13 OK 20260628120000_add_object_size_and_stats.sql (5.61ms)7252026/08/27 09:28:13 goose: successfully migrated database to version: 202606281200007262026/08/27 09:28:13 OK 1_commit_pending_closure.sql (1.07ms)7272026/08/27 09:28:13 OK 2_object_stats_trigger.sql (227.42µs)7282026/08/27 09:28:13 goose: up to current file version: 2729{"timestamp":"2026-08-27T09:28:13.34742Z","level":"ERROR","duration":"71.25µs","resp":"Response { status: 503, version: HTTP/1.1, headers: {\"content-type\": \"application/xml\"}, body: Body { once: b\"<?xml version=\\\"1.0\\\" encoding=\\\"UTF-8\\\"?><Error><Code>SlowDown</Code><Message>bucket creation concurrency limit reached; retry later</Message></Error>\" } }","target":"s3s::service","filename":"/nix/var/nix/builds/nix-57705-2947227838/rustfs-1.0.0-beta.12-vendor/source-git-1/s3s-0.14.1/src/service.rs","line_number":640,"threadName":"rustfs-worker","threadId":"ThreadId(2)"}730{"timestamp":"2026-08-27T09:28:13.347437Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"bb055245-f410-4ccd-8267-98da026eb5e4","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"PUT","uri":"/bucket11/","status_code":503,"duration_ms":0,"result":"server_error","target":"rustfs::server::layer","filename":"rustfs/src/server/layer.rs","line_number":392,"threadName":"rustfs-worker","threadId":"ThreadId(2)"}7312026/08/27 09:28:13 INFO Received uploads request method=POST path=/api/pending_closures732{"timestamp":"2026-08-27T09:28:13.426953Z","level":"ERROR","duration":"55.333µs","resp":"Response { status: 503, version: HTTP/1.1, headers: {\"content-type\": \"application/xml\"}, body: Body { once: b\"<?xml version=\\\"1.0\\\" encoding=\\\"UTF-8\\\"?><Error><Code>SlowDown</Code><Message>bucket creation concurrency limit reached; retry later</Message></Error>\" } }","target":"s3s::service","filename":"/nix/var/nix/builds/nix-57705-2947227838/rustfs-1.0.0-beta.12-vendor/source-git-1/s3s-0.14.1/src/service.rs","line_number":640,"threadName":"rustfs-worker","threadId":"ThreadId(2)"}733{"timestamp":"2026-08-27T09:28:13.426983Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"5cf00572-24b3-4814-9e76-d637b405d9dc","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"PUT","uri":"/bucket10/","status_code":503,"duration_ms":0,"result":"server_error","target":"rustfs::server::layer","filename":"rustfs/src/server/layer.rs","line_number":392,"threadName":"rustfs-worker","threadId":"ThreadId(2)"}7342026/08/27 09:28:13 INFO Received uploads request method=POST path=/api/pending_closures7352026/08/27 09:28:13 INFO Received uploads request method=POST path=/api/pending_closures7362026/08/27 09:28:13 INFO Received uploads request method=POST path=/api/pending_closures7372026/08/27 09:28:13 INFO Received uploads request method=POST path=/api/pending_closures7382026/08/27 09:28:13 INFO Received cleanup request method=DELETE path=/api/pending_closures7392026/08/27 09:28:13 INFO Aborted multipart uploads count=07402026/08/27 09:28:13 INFO Received uploads request method=POST path=/api/pending_closures7412026/08/27 09:28:13 INFO Received cleanup request method=DELETE path=/api/pending_closures7422026/08/27 09:28:13 INFO Received uploads request method=POST path=/api/pending_closures7432026/08/27 09:28:13 INFO Aborted multipart uploads count=17442026/08/27 09:28:13 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete7452026-08-27 09:28:13.692 UTC [13778] ERROR: Closure does not exist: id=17462026-08-27 09:28:13.692 UTC [13778] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 16 at RAISE7472026-08-27 09:28:13.692 UTC [13778] STATEMENT: -- name: CommitPendingClosure :exec748 SELECT commit_pending_closure($1::bigint)749 750--- PASS: TestService_cleanupPendingClosuresHandler (0.75s)751=== CONT TestRedundantMultipartUpload7522026/08/27 09:28:13 INFO Received complete multipart upload request method=POST path=/api/multipart/complete7532026/08/27 09:28:13 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst7542026/08/27 09:28:13 INFO Received uploads request method=POST path=/api/pending_closures755--- PASS: TestPresignedUploadRegisteredBeforeCommit (0.80s)756=== CONT TestReadProxyRangeRequest7572026/08/27 09:28:13 INFO Received uploads request method=POST path=/api/pending_closures7582026/08/27 09:28:13 INFO Received uploads request method=POST path=/api/pending_closures7592026/08/27 09:28:13 INFO Received complete multipart upload request method=POST path=/api/multipart/complete7602026/08/27 09:28:13 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst761--- PASS: TestCompleteMultipartUnregistered (1.03s)762=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT763--- PASS: TestService_Rustfstest (1.08s)764=== CONT TestReadProxyDisabled7652026/08/27 09:28:14 INFO Received complete multipart upload request method=POST path=/api/multipart/complete7662026/08/27 09:28:14 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=YTQ2OGYwMWQtZDRiOC00OTdkLTkwYjEtYjk3NDQwMGUyMGE0LjgyNzg0MjQ4LWFmMWUtNGVlYS1hNDYyLTk0NTAxMjA1NjcxMXgxNzg3ODIyODkzODAyMTQ0MDAw7672026/08/27 09:28:14 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=YTQ2OGYwMWQtZDRiOC00OTdkLTkwYjEtYjk3NDQwMGUyMGE0LjgyNzg0MjQ4LWFmMWUtNGVlYS1hNDYyLTk0NTAxMjA1NjcxMXgxNzg3ODIyODkzODAyMTQ0MDAw parts=1768--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (1.11s)769=== CONT TestReadProxyRootRedirectsToIndexHTML7702026/08/27 09:28:14 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"771--- PASS: TestService_AuthMiddleware (1.20s)772=== CONT TestGracefulShutdownDrainsInflight7732026/08/27 09:28:14 INFO Starting HTTP server address=127.0.0.1:506407742026/08/27 09:28:14 INFO Shutdown signal received, draining in-flight requests timeout=10s775--- PASS: TestGracefulShutdownDrainsInflight (0.07s)776=== CONT TestGCTaskStore_Fail777--- PASS: TestGCTaskStore_Fail (0.00s)778=== CONT TestGCTaskStore_PhaseUpdates779--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)780=== CONT TestReadProxyConditionalGet7812026/08/27 09:28:15 INFO Received complete multipart upload request method=POST path=/api/multipart/complete7822026/08/27 09:28:15 INFO Received complete multipart upload request method=POST path=/api/multipart/complete7832026/08/27 09:28:15 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=YTQ2OGYwMWQtZDRiOC00OTdkLTkwYjEtYjk3NDQwMGUyMGE0Ljg0MmY0OWJmLWNiZjYtNGVkYy1hMTdiLWVhODk0NDkwZTY3OHgxNzg3ODIyODkzNTQ3NTE0MDAw parts=107842026/08/27 09:28:15 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete7852026/08/27 09:28:15 INFO Completed upload id=17862026/08/27 09:28:15 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000007872026/08/27 09:28:15 INFO Received uploads request method=POST path=/api/pending_closures7882026/08/27 09:28:15 INFO Starting cleanup of old closures method=DELETE path=/api/closures7892026/08/27 09:28:15 INFO Aborted multipart uploads count=07902026/08/27 09:28:15 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=07912026/08/27 09:28:15 INFO Vacuumed table table=pending_closures7922026/08/27 09:28:15 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=YTQ2OGYwMWQtZDRiOC00OTdkLTkwYjEtYjk3NDQwMGUyMGE0LmE2NDcxYzRhLWNjYWQtNDVlOS05NDRmLTNkYTcwOTdlODhmZngxNzg3ODIyODkzNDc4Mjg2MDAw parts=107932026/08/27 09:28:15 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete7942026/08/27 09:28:15 INFO Vacuumed table table=pending_objects7952026/08/27 09:28:15 INFO Completed upload id=17962026/08/27 09:28:15 INFO Vacuumed table table=multipart_uploads7972026/08/27 09:28:15 INFO Received uploads request method=POST path=/api/pending_closures7982026/08/27 09:28:15 INFO Received uploads request method=POST path=/api/pending_closures7992026/08/27 09:28:15 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo8002026/08/27 09:28:15 WARN Found objects in DB but missing from S3, will re-upload count=1801--- PASS: TestService_verifyS3Integrity (2.24s)802=== CONT TestGCTaskStore_CompletedAllowsNewTask803--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)804=== CONT TestReadProxyHead8052026/08/27 09:28:15 INFO Vacuumed table table=closures8062026/08/27 09:28:15 INFO Vacuumed table table=objects8072026/08/27 09:28:15 INFO Received get closure request method=GET path=/api/closures/00000000000000000000000000000000808--- PASS: TestService_createPendingClosureHandler (2.34s)809=== CONT TestGCTaskStore_GetReturnsLatest810--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)811=== CONT TestReadProxyInvalidPath8122026-08-27 09:28:15.534 UTC [13801] ERROR: relation "goose_db_version" does not exist at character 368132026-08-27 09:28:15.534 UTC [13801] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8142026-08-27 09:28:15.534 UTC [13802] ERROR: relation "goose_db_version" does not exist at character 368152026-08-27 09:28:15.534 UTC [13802] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8162026/08/27 09:28:15 INFO Received complete multipart upload request method=POST path=/api/multipart/complete8172026-08-27 09:28:15.636 UTC [13803] ERROR: relation "goose_db_version" does not exist at character 368182026-08-27 09:28:15.636 UTC [13803] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8192026/08/27 09:28:15 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=YTQ2OGYwMWQtZDRiOC00OTdkLTkwYjEtYjk3NDQwMGUyMGE0LjI0MWQyNzU3LTMzYmMtNGIyYi04ODUyLTE0M2ZkOTE5MTBhYXgxNzg3ODIyODkzOTAxNDEwMDAw parts=128202026/08/27 09:28:15 INFO Received uploads request method=POST path=/api/pending_closures821--- PASS: TestCompletedNarNotReofferedAcrossClosures (2.67s)822=== CONT TestGCTaskStore_GetEmpty823--- PASS: TestGCTaskStore_GetEmpty (0.00s)824=== CONT TestReadProxy4048252026-08-27 09:28:15.670 UTC [13804] ERROR: relation "goose_db_version" does not exist at character 368262026-08-27 09:28:15.670 UTC [13804] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8272026/08/27 09:28:15 OK 20241026095416_initial_model.sql (69.87ms)8282026/08/27 09:28:15 OK 20251210153512_drop_unused_gin_index.sql (13.09ms)8292026/08/27 09:28:15 OK 20251218171726_add_pins.sql (11.31ms)8302026-08-27 09:28:15.701 UTC [13806] ERROR: relation "goose_db_version" does not exist at character 368312026-08-27 09:28:15.701 UTC [13806] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8322026/08/27 09:28:15 OK 20241026095416_initial_model.sql (95.52ms)8332026/08/27 09:28:15 OK 20251210153512_drop_unused_gin_index.sql (1.54ms)8342026/08/27 09:28:15 OK 20260628120000_add_object_size_and_stats.sql (25.57ms)8352026/08/27 09:28:15 goose: successfully migrated database to version: 202606281200008362026/08/27 09:28:15 OK 20251218171726_add_pins.sql (24.39ms)8372026-08-27 09:28:15.728 UTC [13808] ERROR: relation "goose_db_version" does not exist at character 368382026-08-27 09:28:15.728 UTC [13808] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8392026/08/27 09:28:15 OK 1_commit_pending_closure.sql (2.87ms)8402026/08/27 09:28:15 OK 2_object_stats_trigger.sql (598.38µs)8412026/08/27 09:28:15 goose: up to current file version: 28422026/08/27 09:28:15 OK 20260628120000_add_object_size_and_stats.sql (4.66ms)8432026/08/27 09:28:15 goose: successfully migrated database to version: 202606281200008442026/08/27 09:28:15 OK 1_commit_pending_closure.sql (3.06ms)8452026/08/27 09:28:15 OK 2_object_stats_trigger.sql (462.25µs)8462026/08/27 09:28:15 goose: up to current file version: 28472026/08/27 09:28:15 OK 20241026095416_initial_model.sql (77.96ms)8482026/08/27 09:28:15 OK 20251210153512_drop_unused_gin_index.sql (14.96ms)8492026/08/27 09:28:15 OK 20241026095416_initial_model.sql (67.77ms)8502026/08/27 09:28:15 OK 20251218171726_add_pins.sql (5.68ms)8512026/08/27 09:28:15 OK 20251210153512_drop_unused_gin_index.sql (11.88ms)8522026/08/27 09:28:15 OK 20241026095416_initial_model.sql (59.72ms)8532026/08/27 09:28:15 OK 20251210153512_drop_unused_gin_index.sql (10.42ms)8542026/08/27 09:28:15 OK 20260628120000_add_object_size_and_stats.sql (29.34ms)8552026/08/27 09:28:15 goose: successfully migrated database to version: 202606281200008562026/08/27 09:28:15 OK 1_commit_pending_closure.sql (2.71ms)8572026/08/27 09:28:15 OK 2_object_stats_trigger.sql (944.58µs)8582026/08/27 09:28:15 goose: up to current file version: 28592026/08/27 09:28:15 OK 20251218171726_add_pins.sql (22.91ms)8602026/08/27 09:28:15 OK 20251218171726_add_pins.sql (17.56ms)8612026/08/27 09:28:15 OK 20260628120000_add_object_size_and_stats.sql (35.37ms)8622026/08/27 09:28:15 goose: successfully migrated database to version: 202606281200008632026/08/27 09:28:15 OK 1_commit_pending_closure.sql (12.69ms)8642026/08/27 09:28:15 OK 2_object_stats_trigger.sql (752.25µs)8652026/08/27 09:28:15 goose: up to current file version: 28662026/08/27 09:28:15 INFO Received uploads request method=POST path=/api/pending_closures8672026/08/27 09:28:15 OK 20260628120000_add_object_size_and_stats.sql (45.56ms)8682026/08/27 09:28:15 goose: successfully migrated database to version: 202606281200008692026/08/27 09:28:15 OK 1_commit_pending_closure.sql (7.66ms)8702026/08/27 09:28:15 OK 2_object_stats_trigger.sql (688.25µs)8712026/08/27 09:28:15 goose: up to current file version: 28722026/08/27 09:28:15 OK 20241026095416_initial_model.sql (138.93ms)8732026/08/27 09:28:15 OK 20251210153512_drop_unused_gin_index.sql (11.69ms)8742026/08/27 09:28:15 INFO Received uploads request method=POST path=/api/pending_closures8752026/08/27 09:28:15 OK 20251218171726_add_pins.sql (45.21ms)876--- PASS: TestReadProxyRangeRequest (2.20s)877=== CONT TestGCTaskStore_ConflictDifferentParams878--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)879=== CONT TestReadProxyNarStreaming8802026/08/27 09:28:16 OK 20260628120000_add_object_size_and_stats.sql (49.75ms)8812026/08/27 09:28:16 goose: successfully migrated database to version: 202606281200008822026/08/27 09:28:16 OK 1_commit_pending_closure.sql (2.8ms)8832026/08/27 09:28:16 OK 2_object_stats_trigger.sql (442.88µs)8842026/08/27 09:28:16 goose: up to current file version: 28852026/08/27 09:28:16 INFO Received uploads request method=POST path=/api/pending_closures886--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (2.12s)887=== CONT TestGCTaskStore_DeduplicateSameParams888--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)889=== CONT TestReadProxyNarinfoAlreadyDecompressed890--- PASS: TestReadProxyRootRedirectsToIndexHTML (2.02s)891=== CONT TestClientCADerivations892--- PASS: TestReadProxyConditionalGet (2.03s)893=== CONT TestReadProxyNarinfo894--- PASS: TestReadProxyDisabled (2.30s)895=== CONT TestIsValidCachePath896=== RUN TestIsValidCachePath/narinfo897=== PAUSE TestIsValidCachePath/narinfo898=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars899=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars900=== RUN TestIsValidCachePath/nar_zst901=== PAUSE TestIsValidCachePath/nar_zst902=== RUN TestIsValidCachePath/nar_xz903=== PAUSE TestIsValidCachePath/nar_xz904=== RUN TestIsValidCachePath/nar_bz2905=== PAUSE TestIsValidCachePath/nar_bz2906=== RUN TestIsValidCachePath/nar_uncompressed907=== PAUSE TestIsValidCachePath/nar_uncompressed908=== RUN TestIsValidCachePath/ls909=== PAUSE TestIsValidCachePath/ls910=== RUN TestIsValidCachePath/log911=== PAUSE TestIsValidCachePath/log912=== RUN TestIsValidCachePath/realisation913=== PAUSE TestIsValidCachePath/realisation914=== RUN TestIsValidCachePath/nix-cache-info915=== PAUSE TestIsValidCachePath/nix-cache-info916=== RUN TestIsValidCachePath/index.html917=== PAUSE TestIsValidCachePath/index.html918=== RUN TestIsValidCachePath/traversal_parent919=== PAUSE TestIsValidCachePath/traversal_parent920=== RUN TestIsValidCachePath/traversal_in_middle921=== PAUSE TestIsValidCachePath/traversal_in_middle922=== RUN TestIsValidCachePath/invalid_char_e923=== PAUSE TestIsValidCachePath/invalid_char_e924=== RUN TestIsValidCachePath/invalid_char_u925=== PAUSE TestIsValidCachePath/invalid_char_u926=== RUN TestIsValidCachePath/random_path927=== PAUSE TestIsValidCachePath/random_path928=== RUN TestIsValidCachePath/empty929=== PAUSE TestIsValidCachePath/empty930=== RUN TestIsValidCachePath/leading_slash931=== PAUSE TestIsValidCachePath/leading_slash932=== RUN TestIsValidCachePath/wrong_extension933=== PAUSE TestIsValidCachePath/wrong_extension934=== RUN TestIsValidCachePath/short_hash935=== PAUSE TestIsValidCachePath/short_hash936=== CONT TestParseSingleRange937=== RUN TestParseSingleRange/none938=== PAUSE TestParseSingleRange/none939=== RUN TestParseSingleRange/unknown_unit940=== PAUSE TestParseSingleRange/unknown_unit941=== RUN TestParseSingleRange/multi-range_ignored942=== PAUSE TestParseSingleRange/multi-range_ignored943=== RUN TestParseSingleRange/malformed_no_dash944=== PAUSE TestParseSingleRange/malformed_no_dash945=== RUN TestParseSingleRange/malformed_both_empty946=== PAUSE TestParseSingleRange/malformed_both_empty947=== RUN TestParseSingleRange/malformed_end_before_start948=== PAUSE TestParseSingleRange/malformed_end_before_start949=== RUN TestParseSingleRange/closed950=== PAUSE TestParseSingleRange/closed951=== RUN TestParseSingleRange/open-ended952=== PAUSE TestParseSingleRange/open-ended953=== RUN TestParseSingleRange/end_clamped_to_size954=== PAUSE TestParseSingleRange/end_clamped_to_size955=== RUN TestParseSingleRange/suffix956=== PAUSE TestParseSingleRange/suffix957=== RUN TestParseSingleRange/suffix_exceeds_size958=== PAUSE TestParseSingleRange/suffix_exceeds_size959=== RUN TestParseSingleRange/single_byte960=== PAUSE TestParseSingleRange/single_byte961=== RUN TestParseSingleRange/start_past_EOF962=== PAUSE TestParseSingleRange/start_past_EOF963=== RUN TestParseSingleRange/start_far_past_EOF964=== PAUSE TestParseSingleRange/start_far_past_EOF965=== CONT TestResurrectedObjectNotDeleted9662026-08-27 09:28:16.910 UTC [13823] ERROR: relation "goose_db_version" does not exist at character 369672026-08-27 09:28:16.910 UTC [13823] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9682026-08-27 09:28:16.916 UTC [13824] ERROR: relation "goose_db_version" does not exist at character 369692026-08-27 09:28:16.916 UTC [13824] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9702026/08/27 09:28:16 OK 20241026095416_initial_model.sql (19.5ms)9712026/08/27 09:28:16 OK 20251210153512_drop_unused_gin_index.sql (1.11ms)9722026/08/27 09:28:16 OK 20251218171726_add_pins.sql (15.03ms)9732026-08-27 09:28:16.990 UTC [13825] ERROR: relation "goose_db_version" does not exist at character 369742026-08-27 09:28:16.990 UTC [13825] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9752026/08/27 09:28:17 OK 20260628120000_add_object_size_and_stats.sql (44.76ms)9762026/08/27 09:28:17 goose: successfully migrated database to version: 202606281200009772026/08/27 09:28:17 OK 20241026095416_initial_model.sql (76.59ms)9782026/08/27 09:28:17 OK 20251210153512_drop_unused_gin_index.sql (43.54ms)9792026/08/27 09:28:17 OK 1_commit_pending_closure.sql (43.75ms)9802026/08/27 09:28:17 OK 2_object_stats_trigger.sql (992.46µs)9812026/08/27 09:28:17 goose: up to current file version: 29822026/08/27 09:28:17 OK 20251218171726_add_pins.sql (5.58ms)9832026/08/27 09:28:17 OK 20260628120000_add_object_size_and_stats.sql (42.15ms)9842026/08/27 09:28:17 goose: successfully migrated database to version: 202606281200009852026/08/27 09:28:17 OK 1_commit_pending_closure.sql (9.03ms)9862026/08/27 09:28:17 OK 2_object_stats_trigger.sql (915.42µs)9872026/08/27 09:28:17 goose: up to current file version: 29882026/08/27 09:28:17 OK 20241026095416_initial_model.sql (132.37ms)989--- PASS: TestReadProxyInvalidPath (1.92s)990=== CONT TestOrphanedObjectsGCStressTest9912026/08/27 09:28:17 OK 20251210153512_drop_unused_gin_index.sql (10.27ms)9922026/08/27 09:28:17 OK 20251218171726_add_pins.sql (46.81ms)9932026/08/27 09:28:17 OK 20260628120000_add_object_size_and_stats.sql (45.68ms)9942026/08/27 09:28:17 goose: successfully migrated database to version: 202606281200009952026/08/27 09:28:17 OK 1_commit_pending_closure.sql (9.78ms)9962026/08/27 09:28:17 OK 2_object_stats_trigger.sql (1.27ms)9972026/08/27 09:28:17 goose: up to current file version: 2998--- PASS: TestReadProxyHead (2.21s)999=== CONT TestOrphanedObjectsGC10002026/08/27 09:28:17 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1001--- PASS: TestReadProxy404 (1.84s)1002=== CONT TestObjectStatsTrigger10032026/08/27 09:28:17 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=YTQ2OGYwMWQtZDRiOC00OTdkLTkwYjEtYjk3NDQwMGUyMGE0LmVhYWI3YzllLTI4YTEtNDQ2Yi05ZDE1LWRlNzY0ODI3NGVmZHgxNzg3ODIyODk1ODgzODYzMDAw parts=121004--- PASS: TestRedundantMultipartUpload (3.89s)1005=== CONT TestMultipartCleanup10062026-08-27 09:28:17.645 UTC [13834] ERROR: relation "goose_db_version" does not exist at character 3610072026-08-27 09:28:17.645 UTC [13834] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10082026-08-27 09:28:17.651 UTC [13835] ERROR: relation "goose_db_version" does not exist at character 3610092026-08-27 09:28:17.651 UTC [13835] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10102026-08-27 09:28:17.651 UTC [13836] ERROR: relation "goose_db_version" does not exist at character 3610112026-08-27 09:28:17.651 UTC [13836] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10122026-08-27 09:28:17.759 UTC [13837] ERROR: relation "goose_db_version" does not exist at character 3610132026-08-27 09:28:17.759 UTC [13837] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10142026/08/27 09:28:17 OK 20241026095416_initial_model.sql (72.47ms)10152026/08/27 09:28:17 OK 20241026095416_initial_model.sql (75.73ms)10162026/08/27 09:28:17 OK 20241026095416_initial_model.sql (76.95ms)10172026/08/27 09:28:17 OK 20251210153512_drop_unused_gin_index.sql (4.57ms)10182026/08/27 09:28:17 OK 20251210153512_drop_unused_gin_index.sql (9.59ms)10192026/08/27 09:28:17 OK 20251210153512_drop_unused_gin_index.sql (9.44ms)10202026/08/27 09:28:17 OK 20251218171726_add_pins.sql (26.34ms)10212026/08/27 09:28:17 OK 20251218171726_add_pins.sql (17.24ms)10222026/08/27 09:28:17 OK 20251218171726_add_pins.sql (18.69ms)10232026-08-27 09:28:17.791 UTC [13838] ERROR: relation "goose_db_version" does not exist at character 3610242026-08-27 09:28:17.791 UTC [13838] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10252026/08/27 09:28:17 OK 20260628120000_add_object_size_and_stats.sql (7.54ms)10262026/08/27 09:28:17 goose: successfully migrated database to version: 2026062812000010272026/08/27 09:28:17 OK 20260628120000_add_object_size_and_stats.sql (8.47ms)10282026/08/27 09:28:17 goose: successfully migrated database to version: 2026062812000010292026/08/27 09:28:17 OK 20260628120000_add_object_size_and_stats.sql (8.01ms)10302026/08/27 09:28:17 goose: successfully migrated database to version: 2026062812000010312026/08/27 09:28:17 OK 1_commit_pending_closure.sql (2.96ms)10322026/08/27 09:28:17 OK 1_commit_pending_closure.sql (3.29ms)10332026/08/27 09:28:17 OK 1_commit_pending_closure.sql (4.05ms)10342026/08/27 09:28:17 OK 2_object_stats_trigger.sql (1.59ms)10352026/08/27 09:28:17 goose: up to current file version: 210362026/08/27 09:28:17 OK 2_object_stats_trigger.sql (1.37ms)10372026/08/27 09:28:17 goose: up to current file version: 210382026/08/27 09:28:17 OK 2_object_stats_trigger.sql (1.36ms)10392026/08/27 09:28:17 goose: up to current file version: 210402026/08/27 09:28:17 OK 20241026095416_initial_model.sql (49.97ms)10412026/08/27 09:28:17 OK 20251210153512_drop_unused_gin_index.sql (13.43ms)10422026/08/27 09:28:17 OK 20251218171726_add_pins.sql (87.73ms)10432026/08/27 09:28:17 WARN Rate limiter enabled after throttle name=s3-test rate=510442026/08/27 09:28:17 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."1045=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle1046 throttle_test.go:213: Proxy stats: total=15, throttled=10, completeMultipart=101047 throttle_test.go:215: Rate limiter: enabled=true, rate=5.001048--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (5.00s)1049=== CONT TestServerTLSConfig1050=== RUN TestServerTLSConfig/no_client_CA1051=== PAUSE TestServerTLSConfig/no_client_CA1052=== RUN TestServerTLSConfig/missing_CA_file1053=== PAUSE TestServerTLSConfig/missing_CA_file1054=== RUN TestServerTLSConfig/not_a_PEM_file1055=== PAUSE TestServerTLSConfig/not_a_PEM_file1056=== CONT TestService_NativeMTLS10572026/08/27 09:28:17 OK 20241026095416_initial_model.sql (161.1ms)10582026/08/27 09:28:17 OK 20251210153512_drop_unused_gin_index.sql (8.41ms)10592026/08/27 09:28:17 OK 20260628120000_add_object_size_and_stats.sql (48.23ms)10602026/08/27 09:28:17 goose: successfully migrated database to version: 2026062812000010612026/08/27 09:28:17 OK 20251218171726_add_pins.sql (22.12ms)1062--- PASS: TestReadProxyNarStreaming (2.01s)1063=== CONT TestMetricsInventory10642026/08/27 09:28:17 OK 1_commit_pending_closure.sql (3.77ms)10652026/08/27 09:28:18 OK 2_object_stats_trigger.sql (1.38ms)10662026/08/27 09:28:18 goose: up to current file version: 21067--- PASS: TestReadProxyNarinfoAlreadyDecompressed (1.94s)1068=== CONT TestCacheStatsHandler10692026/08/27 09:28:18 OK 20260628120000_add_object_size_and_stats.sql (43.88ms)10702026/08/27 09:28:18 goose: successfully migrated database to version: 2026062812000010712026/08/27 09:28:18 OK 1_commit_pending_closure.sql (6.37ms)10722026/08/27 09:28:18 OK 2_object_stats_trigger.sql (335.33µs)10732026/08/27 09:28:18 goose: up to current file version: 21074--- PASS: TestReadProxyNarinfo (1.86s)1075=== CONT TestCacheConfigHandler1076=== RUN TestCacheConfigHandler/full_config,_no_issuer1077=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1078=== RUN TestCacheConfigHandler/no_cache_url_configured1079=== PAUSE TestCacheConfigHandler/no_cache_url_configured1080=== RUN TestCacheConfigHandler/no_signing_keys1081=== PAUSE TestCacheConfigHandler/no_signing_keys1082=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1083=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1084=== CONT TestService_AuthMiddleware_OIDC10852026/08/27 09:28:18 INFO OIDC provider initialized name=test10862026/08/27 09:28:18 INFO Created nix-cache-info in bucket bucket=bucket241087--- PASS: TestResurrectedObjectNotDeleted (2.06s)1088=== CONT TestNARDeduplicationMetadataUploadBug10892026-08-27 09:28:18.529 UTC [13854] ERROR: relation "goose_db_version" does not exist at character 3610902026-08-27 09:28:18.529 UTC [13854] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10912026-08-27 09:28:18.575 UTC [13855] ERROR: relation "goose_db_version" does not exist at character 3610922026-08-27 09:28:18.575 UTC [13855] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10932026-08-27 09:28:18.575 UTC [13856] ERROR: relation "goose_db_version" does not exist at character 3610942026-08-27 09:28:18.575 UTC [13856] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10952026/08/27 09:28:18 OK 20241026095416_initial_model.sql (71.26ms)10962026/08/27 09:28:18 OK 20251210153512_drop_unused_gin_index.sql (7.87ms)1097=== NAME TestClientCADerivations1098 client_ca_test.go:136: Built CA derivation: /nix/var/nix/builds/nix-13638-4044143606/TestClientCADerivations3323923083/001/store/jpj30f04m342h2qkn9p3kv8dgyghjdlj-ca-test10992026/08/27 09:28:18 OK 20251218171726_add_pins.sql (2.08ms)11002026/08/27 09:28:18 OK 20260628120000_add_object_size_and_stats.sql (4.64ms)11012026/08/27 09:28:18 goose: successfully migrated database to version: 2026062812000011022026/08/27 09:28:18 OK 20241026095416_initial_model.sql (33.57ms)11032026/08/27 09:28:18 OK 20241026095416_initial_model.sql (33.97ms)11042026/08/27 09:28:18 OK 1_commit_pending_closure.sql (1.26ms)11052026/08/27 09:28:18 OK 20251210153512_drop_unused_gin_index.sql (681.46µs)11062026/08/27 09:28:18 OK 20251210153512_drop_unused_gin_index.sql (870.38µs)11072026/08/27 09:28:18 OK 2_object_stats_trigger.sql (742.63µs)11082026/08/27 09:28:18 goose: up to current file version: 211092026/08/27 09:28:18 OK 20251218171726_add_pins.sql (1.75ms)11102026/08/27 09:28:18 OK 20251218171726_add_pins.sql (1.59ms)11112026/08/27 09:28:18 OK 20260628120000_add_object_size_and_stats.sql (18.39ms)11122026/08/27 09:28:18 goose: successfully migrated database to version: 2026062812000011132026/08/27 09:28:18 OK 1_commit_pending_closure.sql (1.06ms)11142026/08/27 09:28:18 OK 2_object_stats_trigger.sql (324.96µs)11152026/08/27 09:28:18 goose: up to current file version: 211162026/08/27 09:28:18 OK 20260628120000_add_object_size_and_stats.sql (27.16ms)11172026/08/27 09:28:18 goose: successfully migrated database to version: 202606281200001118 client_ca_test.go:139: Found 1 dependencies (including self)11192026/08/27 09:28:18 OK 1_commit_pending_closure.sql (8.85ms)11202026/08/27 09:28:18 OK 2_object_stats_trigger.sql (354.5µs)11212026/08/27 09:28:18 goose: up to current file version: 211222026/08/27 09:28:18 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"11232026/08/27 09:28:18 INFO Received uploads request method=POST path=/api/pending_closures11242026/08/27 09:28:18 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)11252026/08/27 09:28:18 INFO Uploading jpj30f04m342h2qkn9p3kv8dgyghjdlj-ca-test (144B)11262026/08/27 09:28:18 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"11272026/08/27 09:28:18 WARN Failed to register uploaded object key=log/yf10s2qqycrcd7cdcdldvnhppfz0cypm-ca-test.drv error="server returned 404: 404 page not found\n"11282026/08/27 09:28:18 WARN Failed to register uploaded object key=jpj30f04m342h2qkn9p3kv8dgyghjdlj.ls error="server returned 404: 404 page not found\n"11292026/08/27 09:28:18 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign11302026/08/27 09:28:18 INFO Signed narinfos id=1 count=111312026/08/27 09:28:18 INFO Uploading 1 narinfos11322026/08/27 09:28:19 WARN Failed to register uploaded object key=jpj30f04m342h2qkn9p3kv8dgyghjdlj.narinfo error="server returned 404: 404 page not found\n"11332026/08/27 09:28:19 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete1134--- PASS: TestObjectStatsTrigger (1.55s)1135=== CONT TestCreatePendingClosureRejectsOversizedNAR11362026/08/27 09:28:19 INFO Received uploads request method=POST path=/api/pending_closures1137--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)1138=== CONT TestCacheConfigHandlerMaxNarSize1139--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)1140=== CONT TestGenerateLandingPage1141--- PASS: TestGenerateLandingPage (0.00s)1142=== CONT TestService_healthCheckHandler11432026/08/27 09:28:19 INFO Completed upload id=111442026/08/27 09:28:19 INFO Upload complete. (338ms)1145=== NAME TestClientCADerivations1146 client_ca_test.go:180: Narinfo contains CA field: StorePath: /nix/var/nix/builds/nix-13638-4044143606/TestClientCADerivations3323923083/001/store/jpj30f04m342h2qkn9p3kv8dgyghjdlj-ca-test1147 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1148 Compression: zstd1149 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1150 NarSize: 1441151 References: 1152 Deriver: /nix/var/nix/builds/nix-13638-4044143606/TestClientCADerivations3323923083/001/store/yf10s2qqycrcd7cdcdldvnhppfz0cypm-ca-test.drv1153 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1154 client_ca_test.go:185: Checking for realisation files in S3...1155 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1156 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache1157 client_ca_test.go:258: nix copy output: error: binary cache 's3://bucket24?endpoint=http://localhost:50598®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/nix/var/nix/builds/nix-13638-4044143606/TestClientCADerivations3323923083/001/store'1158 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 111592026-08-27 09:28:19.226 UTC [13869] ERROR: relation "goose_db_version" does not exist at character 3611602026-08-27 09:28:19.226 UTC [13869] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1161--- PASS: TestClientCADerivations (3.10s)1162=== CONT TestService_ReadAuthMiddleware11632026/08/27 09:28:19 OK 20241026095416_initial_model.sql (80.96ms)11642026/08/27 09:28:19 OK 20251210153512_drop_unused_gin_index.sql (21.73ms)11652026/08/27 09:28:19 OK 20251218171726_add_pins.sql (27.86ms)11662026-08-27 09:28:19.393 UTC [13872] ERROR: relation "goose_db_version" does not exist at character 3611672026-08-27 09:28:19.393 UTC [13872] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11682026/08/27 09:28:19 OK 20260628120000_add_object_size_and_stats.sql (21.03ms)11692026/08/27 09:28:19 goose: successfully migrated database to version: 2026062812000011702026/08/27 09:28:19 OK 1_commit_pending_closure.sql (2.93ms)11712026/08/27 09:28:19 OK 2_object_stats_trigger.sql (427.71µs)11722026/08/27 09:28:19 goose: up to current file version: 211732026-08-27 09:28:19.437 UTC [13873] ERROR: relation "goose_db_version" does not exist at character 3611742026-08-27 09:28:19.437 UTC [13873] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11752026/08/27 09:28:19 INFO Received uploads request method=POST path=/api/pending_closures11762026/08/27 09:28:19 OK 20241026095416_initial_model.sql (299.08ms)11772026/08/27 09:28:19 OK 20251210153512_drop_unused_gin_index.sql (15.39ms)11782026/08/27 09:28:19 OK 20251218171726_add_pins.sql (39.81ms)11792026/08/27 09:28:19 INFO Received cleanup request method=DELETE path=/api/pending_closures11802026/08/27 09:28:19 INFO Aborted multipart uploads count=111812026/08/27 09:28:19 OK 20241026095416_initial_model.sql (283.24ms)11822026/08/27 09:28:19 OK 20260628120000_add_object_size_and_stats.sql (21.73ms)11832026/08/27 09:28:19 goose: successfully migrated database to version: 2026062812000011842026/08/27 09:28:19 OK 20251210153512_drop_unused_gin_index.sql (6.81ms)1185--- PASS: TestMultipartCleanup (2.23s)1186=== CONT TestService_AuthMiddleware_MTLSBoundSubjects11872026/08/27 09:28:19 OK 1_commit_pending_closure.sql (7.64ms)11882026/08/27 09:28:19 OK 2_object_stats_trigger.sql (978µs)11892026/08/27 09:28:19 goose: up to current file version: 211902026/08/27 09:28:19 OK 20251218171726_add_pins.sql (28.07ms)11912026/08/27 09:28:19 OK 20260628120000_add_object_size_and_stats.sql (50.37ms)11922026/08/27 09:28:19 goose: successfully migrated database to version: 2026062812000011932026/08/27 09:28:19 OK 1_commit_pending_closure.sql (13.62ms)11942026/08/27 09:28:19 OK 2_object_stats_trigger.sql (692.21µs)11952026/08/27 09:28:19 goose: up to current file version: 21196=== NAME TestOrphanedObjectsGC1197 orphaned_objects_gc_test.go:290: GC Test Summary:1198 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A1199 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B1200 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)1201 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)1202 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects1203--- PASS: TestOrphanedObjectsGC (2.64s)1204=== CONT TestService_AuthMiddleware_MTLSProxyHeader12052026-08-27 09:28:20.090 UTC [13876] ERROR: relation "goose_db_version" does not exist at character 3612062026-08-27 09:28:20.090 UTC [13876] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1207--- PASS: TestMetricsInventory (2.11s)1208=== CONT TestClientMultipleUploads12092026/08/27 09:28:20 WARN mTLS auth: subject not in bound subjects subject="CN=reader"12102026/08/27 09:28:20 WARN mTLS auth: subject not in bound subjects subject="CN=writer"1211--- PASS: TestService_NativeMTLS (2.22s)1212=== CONT TestPinProtectsFromGC12132026-08-27 09:28:20.197 UTC [13880] ERROR: relation "goose_db_version" does not exist at character 3612142026-08-27 09:28:20.197 UTC [13880] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12152026/08/27 09:28:20 OK 20241026095416_initial_model.sql (164.62ms)12162026/08/27 09:28:20 OK 20251210153512_drop_unused_gin_index.sql (4.42ms)12172026/08/27 09:28:20 OK 20251218171726_add_pins.sql (48.29ms)12182026/08/27 09:28:20 OK 20260628120000_add_object_size_and_stats.sql (47.46ms)12192026/08/27 09:28:20 goose: successfully migrated database to version: 2026062812000012202026/08/27 09:28:20 OK 1_commit_pending_closure.sql (5.29ms)12212026/08/27 09:28:20 OK 2_object_stats_trigger.sql (760.79µs)12222026/08/27 09:28:20 goose: up to current file version: 212232026/08/27 09:28:20 OK 20241026095416_initial_model.sql (179.41ms)12242026/08/27 09:28:20 OK 20251210153512_drop_unused_gin_index.sql (15.98ms)12252026-08-27 09:28:20.504 UTC [13884] ERROR: relation "goose_db_version" does not exist at character 3612262026-08-27 09:28:20.504 UTC [13884] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12272026/08/27 09:28:20 OK 20251218171726_add_pins.sql (39.27ms)12282026/08/27 09:28:20 OK 20260628120000_add_object_size_and_stats.sql (51.79ms)12292026/08/27 09:28:20 goose: successfully migrated database to version: 2026062812000012302026/08/27 09:28:20 OK 1_commit_pending_closure.sql (10.56ms)12312026/08/27 09:28:20 OK 2_object_stats_trigger.sql (1.18ms)12322026/08/27 09:28:20 goose: up to current file version: 21233--- PASS: TestCacheStatsHandler (2.66s)1234=== CONT TestClientErrorHandling1235=== RUN TestClientErrorHandling/InvalidStorePath1236=== PAUSE TestClientErrorHandling/InvalidStorePath1237=== RUN TestClientErrorHandling/InvalidAuthToken1238=== PAUSE TestClientErrorHandling/InvalidAuthToken1239=== RUN TestClientErrorHandling/ServerNotAvailable1240=== PAUSE TestClientErrorHandling/ServerNotAvailable1241=== CONT TestClientWithDependencies1242=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1243=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1244=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1245=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1246=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1247=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1248=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1249=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1250=== CONT TestGCMetrics12512026/08/27 09:28:20 OK 20241026095416_initial_model.sql (220.64ms)12522026/08/27 09:28:20 OK 20251210153512_drop_unused_gin_index.sql (8.99ms)12532026/08/27 09:28:20 OK 20251218171726_add_pins.sql (68.44ms)12542026/08/27 09:28:20 OK 20260628120000_add_object_size_and_stats.sql (40.65ms)12552026/08/27 09:28:20 goose: successfully migrated database to version: 2026062812000012562026/08/27 09:28:20 OK 1_commit_pending_closure.sql (5.69ms)12572026/08/27 09:28:20 OK 2_object_stats_trigger.sql (799.42µs)12582026/08/27 09:28:20 goose: up to current file version: 212592026/08/27 09:28:21 INFO Created nix-cache-info in bucket bucket=bucket3412602026-08-27 09:28:21.383 UTC [13890] ERROR: relation "goose_db_version" does not exist at character 3612612026-08-27 09:28:21.383 UTC [13890] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1262=== NAME TestNARDeduplicationMetadataUploadBug1263 metadata_upload_test.go:48: First store path: /nix/var/nix/builds/nix-13638-4044143606/TestNARDeduplicationMetadataUploadBug289717502/001/store/z5pykzqp2fs88az309yddsz45mhx4fxq-file1.txt12642026/08/27 09:28:21 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"12652026/08/27 09:28:21 OK 20241026095416_initial_model.sql (127.88ms)12662026/08/27 09:28:21 OK 20251210153512_drop_unused_gin_index.sql (7.45ms)12672026-08-27 09:28:21.598 UTC [13897] ERROR: relation "goose_db_version" does not exist at character 3612682026-08-27 09:28:21.598 UTC [13897] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12692026/08/27 09:28:21 INFO Received uploads request method=POST path=/api/pending_closures12702026/08/27 09:28:21 OK 20251218171726_add_pins.sql (25.7ms)12712026/08/27 09:28:21 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)12722026/08/27 09:28:21 INFO Uploading z5pykzqp2fs88az309yddsz45mhx4fxq-file1.txt (160B)12732026/08/27 09:28:21 OK 20260628120000_add_object_size_and_stats.sql (40.51ms)12742026/08/27 09:28:21 goose: successfully migrated database to version: 2026062812000012752026/08/27 09:28:21 OK 1_commit_pending_closure.sql (7.31ms)12762026/08/27 09:28:21 OK 2_object_stats_trigger.sql (242.5µs)12772026/08/27 09:28:21 goose: up to current file version: 212782026/08/27 09:28:21 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"12792026/08/27 09:28:21 WARN Failed to register uploaded object key=z5pykzqp2fs88az309yddsz45mhx4fxq.ls error="server returned 404: 404 page not found\n"12802026/08/27 09:28:21 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign12812026/08/27 09:28:21 INFO Signed narinfos id=1 count=112822026/08/27 09:28:21 INFO Uploading 1 narinfos12832026/08/27 09:28:21 WARN Failed to register uploaded object key=z5pykzqp2fs88az309yddsz45mhx4fxq.narinfo error="server returned 404: 404 page not found\n"12842026/08/27 09:28:21 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete12852026/08/27 09:28:21 INFO Completed upload id=112862026/08/27 09:28:21 INFO Upload complete. (299ms)1287 metadata_upload_test.go:54: Retrieved narinfo from S3:1288 StorePath: /nix/var/nix/builds/nix-13638-4044143606/TestNARDeduplicationMetadataUploadBug289717502/001/store/z5pykzqp2fs88az309yddsz45mhx4fxq-file1.txt1289 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1290 Compression: zstd1291 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1292 NarSize: 1601293 References: 1294 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1295 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1296 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1297 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}1298--- PASS: TestService_healthCheckHandler (2.81s)1299=== CONT TestGCBugBareHashReferences13002026/08/27 09:28:21 OK 20241026095416_initial_model.sql (229.15ms)1301=== NAME TestNARDeduplicationMetadataUploadBug1302 metadata_upload_test.go:64: Second store path (same content): /nix/var/nix/builds/nix-13638-4044143606/TestNARDeduplicationMetadataUploadBug289717502/001/store/i9km912lmdzhv09546lqs68c9q76qfd4-file2.txt13032026/08/27 09:28:21 OK 20251210153512_drop_unused_gin_index.sql (50.13ms)13042026/08/27 09:28:21 OK 20251218171726_add_pins.sql (34.89ms)13052026/08/27 09:28:21 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"13062026/08/27 09:28:22 OK 20260628120000_add_object_size_and_stats.sql (36.43ms)13072026/08/27 09:28:22 goose: successfully migrated database to version: 2026062812000013082026/08/27 09:28:22 INFO Received uploads request method=POST path=/api/pending_closures13092026/08/27 09:28:22 OK 1_commit_pending_closure.sql (2.19ms)13102026/08/27 09:28:22 OK 2_object_stats_trigger.sql (306.25µs)13112026/08/27 09:28:22 goose: up to current file version: 213122026/08/27 09:28:22 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)13132026/08/27 09:28:22 WARN Failed to register uploaded object key=i9km912lmdzhv09546lqs68c9q76qfd4.ls error="server returned 404: 404 page not found\n"13142026/08/27 09:28:22 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign13152026/08/27 09:28:22 INFO Signed narinfos id=2 count=113162026/08/27 09:28:22 INFO Uploading 1 narinfos13172026/08/27 09:28:22 WARN Failed to register uploaded object key=i9km912lmdzhv09546lqs68c9q76qfd4.narinfo error="server returned 404: 404 page not found\n"13182026/08/27 09:28:22 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete13192026/08/27 09:28:22 INFO Completed upload id=213202026/08/27 09:28:22 INFO Upload complete. (206ms)1321 metadata_upload_test.go:76: Retrieved narinfo from S3:1322 StorePath: /nix/var/nix/builds/nix-13638-4044143606/TestNARDeduplicationMetadataUploadBug289717502/001/store/i9km912lmdzhv09546lqs68c9q76qfd4-file2.txt1323 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1324 Compression: zstd1325 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1326 NarSize: 1601327 References: 1328 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1329 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1330 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1331 {"version":1,"root":{"type":"regular","size":44}}13322026-08-27 09:28:22.188 UTC [13909] ERROR: relation "goose_db_version" does not exist at character 3613332026-08-27 09:28:22.188 UTC [13909] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13342026/08/27 09:28:22 WARN mTLS auth: subject not in bound subjects subject="CN=writer"1335--- PASS: TestService_ReadAuthMiddleware (3.04s)1336=== CONT TestGCTaskStore_StartNew1337--- PASS: TestGCTaskStore_StartNew (0.00s)1338=== CONT TestClientIntegration1339--- PASS: TestNARDeduplicationMetadataUploadBug (3.87s)1340=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info13412026/08/27 09:28:22 INFO Received uploads request method=POST path=/1342=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key13432026/08/27 09:28:22 INFO Received request for more parts method=POST path=/1344=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key13452026/08/27 09:28:22 INFO Received complete multipart upload request method=POST path=/1346=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal13472026/08/27 09:28:22 INFO Received uploads request method=POST path=/1348--- PASS: TestUploadHandlersRejectInvalidKeys (0.01s)1349 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1350 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1351 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1352 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1353=== CONT TestProxyWriteTimeout/narinfo1354=== CONT TestProxyWriteTimeout/unknown_size1355=== CONT TestProxyWriteTimeout/10_GiB_nar1356=== CONT TestProxyWriteTimeout/1_GiB_nar1357--- PASS: TestProxyWriteTimeout (0.04s)1358 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1359 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1360 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1361 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1362=== CONT TestIsValidUploadKey/narinfo1363=== CONT TestIsValidUploadKey/unknown_type1364=== CONT TestIsValidUploadKey/empty_key1365=== CONT TestIsValidUploadKey/absolute1366=== CONT TestIsValidUploadKey/traversal_nar1367=== CONT TestIsValidUploadKey/traversal1368=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1369=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1370=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1371=== CONT TestIsValidUploadKey/index.html1372=== CONT TestIsValidUploadKey/nix-cache-info1373=== CONT TestIsValidUploadKey/realisation_plus_in_output1374=== CONT TestIsValidUploadKey/realisation1375=== CONT TestIsValidUploadKey/build_log_equals1376=== CONT TestIsValidUploadKey/build_log_question_mark1377=== CONT TestIsValidUploadKey/build_log_plus_in_name1378=== CONT TestIsValidUploadKey/build_log_home-manager_file1379=== CONT TestIsValidUploadKey/build_log1380=== CONT TestIsValidUploadKey/listing1381=== CONT TestIsValidUploadKey/nar_plain1382=== CONT TestIsValidUploadKey/nar_xz1383=== CONT TestIsValidUploadKey/nar_zst1384--- PASS: TestIsValidUploadKey (0.04s)1385 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1386 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1387 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1388 --- PASS: TestIsValidUploadKey/absolute (0.00s)1389 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1390 --- PASS: TestIsValidUploadKey/traversal (0.00s)1391 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1392 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1393 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1394 --- PASS: TestIsValidUploadKey/index.html (0.00s)1395 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1396 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1397 --- PASS: TestIsValidUploadKey/realisation (0.00s)1398 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1399 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1400 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1401 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1402 --- PASS: TestIsValidUploadKey/build_log (0.00s)1403 --- PASS: TestIsValidUploadKey/listing (0.00s)1404 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1405 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1406 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1407=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure14082026/08/27 09:28:22 INFO Received uploads request method=POST path=/14092026-08-27 09:28:22.461 UTC [13912] ERROR: relation "goose_db_version" does not exist at character 3614102026-08-27 09:28:22.461 UTC [13912] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14112026/08/27 09:28:22 OK 20241026095416_initial_model.sql (203.31ms)14122026/08/27 09:28:22 OK 20251210153512_drop_unused_gin_index.sql (4.47ms)14132026-08-27 09:28:22.480 UTC [13913] ERROR: relation "goose_db_version" does not exist at character 3614142026-08-27 09:28:22.480 UTC [13913] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14152026/08/27 09:28:22 OK 20251218171726_add_pins.sql (25.05ms)14162026/08/27 09:28:22 OK 20260628120000_add_object_size_and_stats.sql (34.29ms)14172026/08/27 09:28:22 goose: successfully migrated database to version: 2026062812000014182026/08/27 09:28:22 OK 1_commit_pending_closure.sql (6.48ms)14192026-08-27 09:28:22.545 UTC [13914] ERROR: relation "goose_db_version" does not exist at character 3614202026-08-27 09:28:22.545 UTC [13914] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14212026/08/27 09:28:22 OK 2_object_stats_trigger.sql (504.75µs)14222026/08/27 09:28:22 goose: up to current file version: 21423=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts14242026/08/27 09:28:22 INFO Received request for more parts method=POST path=/1425=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart14262026/08/27 09:28:22 INFO Received complete multipart upload request method=POST path=/14272026/08/27 09:28:22 OK 20241026095416_initial_model.sql (98.86ms)1428--- PASS: TestUploadHandlersRejectOversizedBody (0.05s)1429 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.29s)1430 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.02s)1431 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.02s)1432=== CONT TestIsValidCachePath/narinfo1433=== CONT TestIsValidCachePath/index.html1434=== CONT TestIsValidCachePath/short_hash1435=== CONT TestIsValidCachePath/wrong_extension1436=== CONT TestIsValidCachePath/leading_slash1437=== CONT TestIsValidCachePath/empty1438=== CONT TestIsValidCachePath/random_path1439=== CONT TestIsValidCachePath/invalid_char_u1440=== CONT TestIsValidCachePath/invalid_char_e1441=== CONT TestIsValidCachePath/traversal_in_middle1442=== CONT TestIsValidCachePath/traversal_parent1443=== CONT TestIsValidCachePath/nar_uncompressed1444=== CONT TestIsValidCachePath/nix-cache-info1445=== CONT TestIsValidCachePath/realisation1446=== CONT TestIsValidCachePath/log1447=== CONT TestIsValidCachePath/ls1448=== CONT TestIsValidCachePath/nar_xz1449=== CONT TestIsValidCachePath/nar_bz21450=== CONT TestIsValidCachePath/nar_zst1451=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1452--- PASS: TestIsValidCachePath (0.00s)1453 --- PASS: TestIsValidCachePath/narinfo (0.00s)1454 --- PASS: TestIsValidCachePath/index.html (0.00s)1455 --- PASS: TestIsValidCachePath/short_hash (0.00s)1456 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1457 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1458 --- PASS: TestIsValidCachePath/empty (0.00s)1459 --- PASS: TestIsValidCachePath/random_path (0.00s)1460 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1461 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1462 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1463 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1464 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1465 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1466 --- PASS: TestIsValidCachePath/realisation (0.00s)1467 --- PASS: TestIsValidCachePath/log (0.00s)1468 --- PASS: TestIsValidCachePath/ls (0.00s)1469 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1470 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1471 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1472 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1473=== CONT TestParseSingleRange/none1474=== CONT TestParseSingleRange/open-ended1475=== CONT TestParseSingleRange/start_far_past_EOF1476=== CONT TestParseSingleRange/start_past_EOF1477=== CONT TestParseSingleRange/single_byte1478=== CONT TestParseSingleRange/suffix_exceeds_size1479=== CONT TestParseSingleRange/suffix1480=== CONT TestParseSingleRange/end_clamped_to_size1481=== CONT TestParseSingleRange/malformed_both_empty1482=== CONT TestParseSingleRange/closed1483=== CONT TestParseSingleRange/malformed_end_before_start1484=== CONT TestParseSingleRange/multi-range_ignored1485=== CONT TestParseSingleRange/malformed_no_dash1486=== CONT TestParseSingleRange/unknown_unit1487--- PASS: TestParseSingleRange (0.00s)1488 --- PASS: TestParseSingleRange/none (0.00s)1489 --- PASS: TestParseSingleRange/open-ended (0.00s)1490 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1491 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1492 --- PASS: TestParseSingleRange/single_byte (0.00s)1493 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1494 --- PASS: TestParseSingleRange/suffix (0.00s)1495 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1496 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1497 --- PASS: TestParseSingleRange/closed (0.00s)1498 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1499 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1500 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1501 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1502=== CONT TestServerTLSConfig/no_client_CA1503=== CONT TestServerTLSConfig/not_a_PEM_file15042026/08/27 09:28:22 OK 20251210153512_drop_unused_gin_index.sql (11.81ms)15052026/08/27 09:28:22 OK 20241026095416_initial_model.sql (92.91ms)1506=== CONT TestServerTLSConfig/missing_CA_file1507--- PASS: TestServerTLSConfig (0.00s)1508 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1509 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.02s)1510 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1511=== CONT TestCacheConfigHandler/full_config,_no_issuer1512=== CONT TestCacheConfigHandler/no_signing_keys1513=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1514=== CONT TestCacheConfigHandler/no_cache_url_configured1515--- PASS: TestCacheConfigHandler (0.00s)1516 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)1517 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)1518 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)1519 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)1520=== CONT TestClientErrorHandling/InvalidStorePath15212026/08/27 09:28:22 OK 20251210153512_drop_unused_gin_index.sql (14.16ms)15222026/08/27 09:28:22 OK 20251218171726_add_pins.sql (34.22ms)15232026/08/27 09:28:22 OK 20251218171726_add_pins.sql (27.04ms)15242026/08/27 09:28:22 OK 20260628120000_add_object_size_and_stats.sql (13.58ms)15252026/08/27 09:28:22 goose: successfully migrated database to version: 2026062812000015262026/08/27 09:28:22 OK 1_commit_pending_closure.sql (7.37ms)15272026/08/27 09:28:22 OK 2_object_stats_trigger.sql (211.79µs)15282026/08/27 09:28:22 goose: up to current file version: 215292026/08/27 09:28:22 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"15302026/08/27 09:28:22 WARN mTLS auth: bound subjects configured but subject DN unavailable15312026/08/27 09:28:22 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1532--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (2.90s)1533=== CONT TestClientErrorHandling/ServerNotAvailable15342026/08/27 09:28:22 OK 20260628120000_add_object_size_and_stats.sql (58.42ms)15352026/08/27 09:28:22 goose: successfully migrated database to version: 2026062812000015362026/08/27 09:28:22 OK 1_commit_pending_closure.sql (8.13ms)15372026/08/27 09:28:22 OK 2_object_stats_trigger.sql (266.29µs)15382026/08/27 09:28:22 goose: up to current file version: 215392026/08/27 09:28:22 OK 20241026095416_initial_model.sql (246.62ms)15402026/08/27 09:28:22 OK 20251210153512_drop_unused_gin_index.sql (13.69ms)1541--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (2.85s)1542=== CONT TestClientErrorHandling/InvalidAuthToken15432026/08/27 09:28:22 OK 20251218171726_add_pins.sql (36.05ms)15442026/08/27 09:28:22 OK 20260628120000_add_object_size_and_stats.sql (59.07ms)15452026/08/27 09:28:22 goose: successfully migrated database to version: 2026062812000015462026/08/27 09:28:22 OK 1_commit_pending_closure.sql (8.27ms)15472026/08/27 09:28:22 OK 2_object_stats_trigger.sql (382.63µs)15482026/08/27 09:28:22 goose: up to current file version: 215492026/08/27 09:28:22 INFO Created nix-cache-info in bucket bucket=bucket3915502026-08-27 09:28:23.028 UTC [13921] ERROR: relation "goose_db_version" does not exist at character 3615512026-08-27 09:28:23.028 UTC [13921] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15522026/08/27 09:28:23 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config15532026/08/27 09:28:23 INFO Created nix-cache-info in bucket bucket=bucket4015542026/08/27 09:28:23 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=194.465555ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config15552026-08-27 09:28:23.248 UTC [13928] ERROR: relation "goose_db_version" does not exist at character 3615562026-08-27 09:28:23.248 UTC [13928] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15572026/08/27 09:28:23 OK 20241026095416_initial_model.sql (166.87ms)1558=== NAME TestClientMultipleUploads1559 client_integration_test.go:338: Created store path 0: /nix/var/nix/builds/nix-13638-4044143606/TestClientMultipleUploads3195204571/001/store/i5b335xlb829c61s359ijldk8vm3wgwh-test-file-0.txt15602026/08/27 09:28:23 OK 20251210153512_drop_unused_gin_index.sql (5.61ms)15612026/08/27 09:28:23 OK 20251218171726_add_pins.sql (22.99ms)15622026/08/27 09:28:23 OK 20260628120000_add_object_size_and_stats.sql (24.12ms)15632026/08/27 09:28:23 goose: successfully migrated database to version: 2026062812000015642026/08/27 09:28:23 OK 1_commit_pending_closure.sql (9.66ms)15652026/08/27 09:28:23 OK 2_object_stats_trigger.sql (235.38µs)15662026/08/27 09:28:23 goose: up to current file version: 21567 client_integration_test.go:338: Created store path 1: /nix/var/nix/builds/nix-13638-4044143606/TestClientMultipleUploads3195204571/001/store/l2fw9pji48k9whsd4j0wcj68gaph8w6j-test-file-1.txt15682026/08/27 09:28:23 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=414.714863ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config1569 client_integration_test.go:338: Created store path 2: /nix/var/nix/builds/nix-13638-4044143606/TestClientMultipleUploads3195204571/001/store/3p9lxb06vrdkxzllgpz2q199qx63h7sa-test-file-2.txt15702026/08/27 09:28:23 OK 20241026095416_initial_model.sql (214.36ms)15712026/08/27 09:28:23 INFO Created nix-cache-info in bucket bucket=bucket4115722026/08/27 09:28:23 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"15732026/08/27 09:28:23 OK 20251210153512_drop_unused_gin_index.sql (12.27ms)15742026/08/27 09:28:23 OK 20251218171726_add_pins.sql (13.59ms)1575=== NAME TestPinProtectsFromGC1576 client_integration_test.go:646: Pinned store path: /nix/var/nix/builds/nix-13638-4044143606/TestPinProtectsFromGC469718993/001/store/igm8pggwzm83sd1117r0548lwbfdx2jm-pinned-file.txt1577 client_integration_test.go:647: Unpinned store path: /nix/var/nix/builds/nix-13638-4044143606/TestPinProtectsFromGC469718993/001/store/bm4qx2n40iddd6nhmq6l8bx3khx3yka5-unpinned-file.txt15782026/08/27 09:28:23 OK 20260628120000_add_object_size_and_stats.sql (34.19ms)15792026/08/27 09:28:23 goose: successfully migrated database to version: 2026062812000015802026/08/27 09:28:23 INFO Received uploads request method=POST path=/api/pending_closures15812026/08/27 09:28:23 OK 1_commit_pending_closure.sql (42.56ms)15822026/08/27 09:28:23 OK 2_object_stats_trigger.sql (376.08µs)15832026/08/27 09:28:23 goose: up to current file version: 215842026/08/27 09:28:23 INFO Received uploads request method=POST path=/api/pending_closures15852026/08/27 09:28:23 INFO Received uploads request method=POST path=/api/pending_closures15862026/08/27 09:28:23 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)15872026/08/27 09:28:23 INFO Uploading i5b335xlb829c61s359ijldk8vm3wgwh-test-file-0.txt (160B)15882026/08/27 09:28:23 INFO Uploading l2fw9pji48k9whsd4j0wcj68gaph8w6j-test-file-1.txt (160B)15892026/08/27 09:28:23 INFO Uploading 3p9lxb06vrdkxzllgpz2q199qx63h7sa-test-file-2.txt (160B)15902026/08/27 09:28:23 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"15912026/08/27 09:28:23 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"15922026/08/27 09:28:23 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"15932026/08/27 09:28:23 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"15942026/08/27 09:28:23 WARN Failed to register uploaded object key=i5b335xlb829c61s359ijldk8vm3wgwh.ls error="server returned 404: 404 page not found\n"15952026/08/27 09:28:23 WARN Failed to register uploaded object key=3p9lxb06vrdkxzllgpz2q199qx63h7sa.ls error="server returned 404: 404 page not found\n"15962026/08/27 09:28:23 WARN Failed to register uploaded object key=l2fw9pji48k9whsd4j0wcj68gaph8w6j.ls error="server returned 404: 404 page not found\n"15972026/08/27 09:28:23 INFO Received sign narinfos request method=POST path=/api/pending_closures/3/sign15982026/08/27 09:28:23 INFO Signed narinfos id=3 count=115992026/08/27 09:28:23 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign16002026/08/27 09:28:23 INFO Signed narinfos id=1 count=116012026/08/27 09:28:23 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign16022026/08/27 09:28:23 INFO Signed narinfos id=2 count=116032026/08/27 09:28:23 INFO Uploading 3 narinfos16042026/08/27 09:28:23 INFO Received uploads request method=POST path=/api/pending_closures16052026/08/27 09:28:23 WARN Failed to register uploaded object key=l2fw9pji48k9whsd4j0wcj68gaph8w6j.narinfo error="server returned 404: 404 page not found\n"16062026/08/27 09:28:23 WARN Failed to register uploaded object key=3p9lxb06vrdkxzllgpz2q199qx63h7sa.narinfo error="server returned 404: 404 page not found\n"16072026/08/27 09:28:23 WARN Failed to register uploaded object key=i5b335xlb829c61s359ijldk8vm3wgwh.narinfo error="server returned 404: 404 page not found\n"16082026/08/27 09:28:23 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete16092026/08/27 09:28:23 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)16102026/08/27 09:28:23 INFO Uploading igm8pggwzm83sd1117r0548lwbfdx2jm-pinned-file.txt (128B)16112026/08/27 09:28:23 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=819.31332ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config16122026/08/27 09:28:23 INFO Completed upload id=116132026/08/27 09:28:23 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete16142026/08/27 09:28:23 INFO Completed upload id=216152026/08/27 09:28:23 INFO Received complete upload request method=POST path=/api/pending_closures/3/complete16162026/08/27 09:28:23 INFO Completed upload id=316172026/08/27 09:28:23 INFO Upload complete. (349ms)1618=== NAME TestClientMultipleUploads1619 client_integration_test.go:349: Uploaded 3 paths in 378.86ms16202026/08/27 09:28:23 INFO Aborted multipart uploads count=016212026/08/27 09:28:23 WARN Force mode enabled - objects will be deleted immediately without grace period16222026/08/27 09:28:23 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"16232026/08/27 09:28:23 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=016242026/08/27 09:28:23 INFO Vacuumed table table=pending_closures16252026/08/27 09:28:23 INFO Vacuumed table table=pending_objects16262026/08/27 09:28:23 INFO Vacuumed table table=multipart_uploads16272026/08/27 09:28:23 INFO Vacuumed table table=closures16282026/08/27 09:28:23 INFO Vacuumed table table=objects1629--- PASS: TestGCMetrics (3.09s)1630=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token16312026/08/27 09:28:23 INFO OIDC auth successful provider=test1632=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected16332026/08/27 09:28:23 WARN Authentication failed token_preview=not-a-valid-jwt token_length=15 oidc_error="no provider could verify the token (signature or issuer mismatch)" oidc_provider="" tried_providers=[test]1634=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1635=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected16362026/08/27 09:28:23 WARN Authentication failed token_preview=eyJhbGciOi...epEpmdncKQ 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]1637--- PASS: TestService_AuthMiddleware_OIDC (2.67s)1638 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)1639 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)1640 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)1641 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)16422026/08/27 09:28:23 WARN Failed to register uploaded object key=igm8pggwzm83sd1117r0548lwbfdx2jm.ls error="server returned 404: 404 page not found\n"16432026/08/27 09:28:23 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign16442026/08/27 09:28:23 INFO Signed narinfos id=1 count=116452026/08/27 09:28:23 INFO Uploading 1 narinfos1646--- PASS: TestClientMultipleUploads (3.81s)16472026/08/27 09:28:23 WARN Failed to register uploaded object key=igm8pggwzm83sd1117r0548lwbfdx2jm.narinfo error="server returned 404: 404 page not found\n"16482026/08/27 09:28:23 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete16492026/08/27 09:28:23 INFO Completed upload id=116502026/08/27 09:28:23 INFO Upload complete. (332ms)16512026-08-27 09:28:23.949 UTC [13956] ERROR: relation "goose_db_version" does not exist at character 3616522026-08-27 09:28:23.949 UTC [13956] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1653=== NAME TestClientWithDependencies1654 client_integration_test.go:593: Built derivation: /nix/var/nix/builds/nix-13638-4044143606/TestClientWithDependencies1077520362/001/store/nl0d3fb84yzv2vjxjvmyf658q2nr0y8d-test-script16552026/08/27 09:28:23 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"16562026/08/27 09:28:24 OK 20241026095416_initial_model.sql (45.27ms)16572026/08/27 09:28:24 OK 20251210153512_drop_unused_gin_index.sql (8.14ms)16582026-08-27 09:28:24.029 UTC [13962] ERROR: relation "goose_db_version" does not exist at character 3616592026-08-27 09:28:24.029 UTC [13962] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1660 client_integration_test.go:595: Found 1 dependencies (including self)16612026/08/27 09:28:24 INFO Received uploads request method=POST path=/api/pending_closures16622026/08/27 09:28:24 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)16632026/08/27 09:28:24 INFO Uploading bm4qx2n40iddd6nhmq6l8bx3khx3yka5-unpinned-file.txt (128B)16642026/08/27 09:28:24 OK 20251218171726_add_pins.sql (18.15ms)16652026/08/27 09:28:24 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"16662026/08/27 09:28:24 OK 20260628120000_add_object_size_and_stats.sql (23.1ms)16672026/08/27 09:28:24 goose: successfully migrated database to version: 2026062812000016682026/08/27 09:28:24 OK 1_commit_pending_closure.sql (1.48ms)16692026/08/27 09:28:24 OK 2_object_stats_trigger.sql (221.25µs)16702026/08/27 09:28:24 goose: up to current file version: 216712026/08/27 09:28:24 WARN Failed to register uploaded object key=bm4qx2n40iddd6nhmq6l8bx3khx3yka5.ls error="server returned 404: 404 page not found\n"16722026/08/27 09:28:24 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign16732026/08/27 09:28:24 INFO Signed narinfos id=2 count=116742026/08/27 09:28:24 INFO Uploading 1 narinfos16752026/08/27 09:28:24 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"16762026/08/27 09:28:24 INFO Received uploads request method=POST path=/api/pending_closures16772026/08/27 09:28:24 WARN Failed to register uploaded object key=bm4qx2n40iddd6nhmq6l8bx3khx3yka5.narinfo error="server returned 404: 404 page not found\n"16782026/08/27 09:28:24 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete16792026/08/27 09:28:24 INFO Completed upload id=216802026/08/27 09:28:24 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)16812026/08/27 09:28:24 INFO Uploading nl0d3fb84yzv2vjxjvmyf658q2nr0y8d-test-script (136B)16822026/08/27 09:28:24 INFO Upload complete. (177ms)16832026/08/27 09:28:24 INFO Received create pin request method=POST path=/api/pins/myapp16842026/08/27 09:28:24 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"16852026/08/27 09:28:24 WARN Failed to register uploaded object key=log/40rwg9bpnamymzqfw5canl2hj1icw57x-test-script.drv error="server returned 404: 404 page not found\n"16862026/08/27 09:28:24 WARN Failed to register uploaded object key=nl0d3fb84yzv2vjxjvmyf658q2nr0y8d.ls error="server returned 404: 404 page not found\n"16872026/08/27 09:28:24 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign16882026/08/27 09:28:24 INFO Signed narinfos id=1 count=116892026/08/27 09:28:24 INFO Uploading 1 narinfos16902026/08/27 09:28:24 INFO Created/updated pin name=myapp store_path=/nix/var/nix/builds/nix-13638-4044143606/TestPinProtectsFromGC469718993/001/store/igm8pggwzm83sd1117r0548lwbfdx2jm-pinned-file.txt narinfo_key=igm8pggwzm83sd1117r0548lwbfdx2jm.narinfo16912026/08/27 09:28:24 INFO Starting cleanup of old closures method=DELETE path=/api/closures16922026/08/27 09:28:24 INFO Garbage collection started16932026/08/27 09:28:24 INFO Aborted multipart uploads count=016942026/08/27 09:28:24 WARN Force mode enabled - objects will be deleted immediately without grace period16952026/08/27 09:28:24 OK 20241026095416_initial_model.sql (169.58ms)16962026/08/27 09:28:24 OK 20251210153512_drop_unused_gin_index.sql (7.09ms)16972026/08/27 09:28:24 WARN Failed to register uploaded object key=nl0d3fb84yzv2vjxjvmyf658q2nr0y8d.narinfo error="server returned 404: 404 page not found\n"16982026/08/27 09:28:24 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete16992026/08/27 09:28:24 OK 20251218171726_add_pins.sql (7.95ms)17002026/08/27 09:28:24 INFO Completed upload id=117012026/08/27 09:28:24 INFO Upload complete. (189ms)1702 client_integration_test.go:597: Skipping nix copy test - isolated store (/nix/var/nix/builds/nix-13638-4044143606/TestClientWithDependencies1077520362/001/store) requires matching store prefix17032026/08/27 09:28:24 OK 20260628120000_add_object_size_and_stats.sql (14.08ms)17042026/08/27 09:28:24 goose: successfully migrated database to version: 202606281200001705--- PASS: TestClientWithDependencies (3.57s)17062026/08/27 09:28:24 OK 1_commit_pending_closure.sql (1.42ms)17072026/08/27 09:28:24 OK 2_object_stats_trigger.sql (225.33µs)17082026/08/27 09:28:24 goose: up to current file version: 217092026/08/27 09:28:24 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=017102026/08/27 09:28:24 INFO Vacuumed table table=pending_closures17112026/08/27 09:28:24 INFO Vacuumed table table=pending_objects17122026/08/27 09:28:24 INFO Vacuumed table table=multipart_uploads17132026/08/27 09:28:24 INFO Vacuumed table table=closures17142026/08/27 09:28:24 INFO Vacuumed table table=objects17152026/08/27 09:28:24 INFO Created nix-cache-info in bucket bucket=bucket4417162026-08-27 09:28:24.450 UTC [13973] ERROR: relation "goose_db_version" does not exist at character 3617172026-08-27 09:28:24.450 UTC [13973] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1718--- PASS: TestGCBugBareHashReferences (2.60s)17192026-08-27 09:28:24.485 UTC [13976] ERROR: relation "goose_db_version" does not exist at character 3617202026-08-27 09:28:24.485 UTC [13976] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17212026/08/27 09:28:24 OK 20241026095416_initial_model.sql (32.52ms)17222026/08/27 09:28:24 OK 20251210153512_drop_unused_gin_index.sql (15.1ms)17232026/08/27 09:28:24 OK 20251218171726_add_pins.sql (14.34ms)17242026/08/27 09:28:24 OK 20260628120000_add_object_size_and_stats.sql (11.27ms)17252026/08/27 09:28:24 goose: successfully migrated database to version: 202606281200001726=== NAME TestClientIntegration1727 client_integration_test.go:276: Created store path: /nix/var/nix/builds/nix-13638-4044143606/TestClientIntegration2810498841/002/store/b14nwb0jggbal2iyraj1jvi0x56ly5fm-test-file.txt17282026/08/27 09:28:24 OK 1_commit_pending_closure.sql (6.12ms)17292026/08/27 09:28:24 OK 2_object_stats_trigger.sql (205.92µs)17302026/08/27 09:28:24 goose: up to current file version: 217312026/08/27 09:28:24 OK 20241026095416_initial_model.sql (94.53ms)17322026/08/27 09:28:24 OK 20251210153512_drop_unused_gin_index.sql (15.75ms)17332026/08/27 09:28:24 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"17342026/08/27 09:28:24 OK 20251218171726_add_pins.sql (15.98ms)17352026/08/27 09:28:24 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.642611677s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config17362026/08/27 09:28:24 OK 20260628120000_add_object_size_and_stats.sql (26.17ms)17372026/08/27 09:28:24 goose: successfully migrated database to version: 2026062812000017382026/08/27 09:28:24 OK 1_commit_pending_closure.sql (4.47ms)17392026/08/27 09:28:24 OK 2_object_stats_trigger.sql (225.88µs)17402026/08/27 09:28:24 goose: up to current file version: 217412026/08/27 09:28:24 INFO Received uploads request method=POST path=/api/pending_closures17422026/08/27 09:28:24 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)17432026/08/27 09:28:24 INFO Uploading b14nwb0jggbal2iyraj1jvi0x56ly5fm-test-file.txt (152B)17442026/08/27 09:28:24 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"17452026/08/27 09:28:24 WARN Failed to register uploaded object key=b14nwb0jggbal2iyraj1jvi0x56ly5fm.ls error="server returned 404: 404 page not found\n"17462026/08/27 09:28:24 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign17472026/08/27 09:28:24 INFO Signed narinfos id=1 count=117482026/08/27 09:28:24 INFO Uploading 1 narinfos17492026/08/27 09:28:24 WARN Failed to register uploaded object key=b14nwb0jggbal2iyraj1jvi0x56ly5fm.narinfo error="server returned 404: 404 page not found\n"17502026/08/27 09:28:24 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete17512026/08/27 09:28:24 INFO Completed upload id=117522026/08/27 09:28:24 INFO Upload complete. (233ms)1753 client_integration_test.go:292: Retrieved narinfo from S3:1754 StorePath: /nix/var/nix/builds/nix-13638-4044143606/TestClientIntegration2810498841/002/store/b14nwb0jggbal2iyraj1jvi0x56ly5fm-test-file.txt1755 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1756 Compression: zstd1757 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11758 NarSize: 1521759 References: 1760 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11761 client_integration_test.go:293: Retrieved .ls file from S3 (compressed size: 77 bytes)1762 client_integration_test.go:293: Decompressed .ls content (64 bytes):1763 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1764 client_integration_test.go:296: Testing garbage collection...17652026/08/27 09:28:24 INFO Starting cleanup of old closures method=DELETE path=/api/closures17662026/08/27 09:28:24 INFO Garbage collection started17672026/08/27 09:28:24 INFO Aborted multipart uploads count=017682026/08/27 09:28:24 WARN Force mode enabled - objects will be deleted immediately without grace period17692026/08/27 09:28:24 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=017702026/08/27 09:28:24 INFO Vacuumed table table=pending_closures17712026/08/27 09:28:24 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"17722026/08/27 09:28:24 INFO Vacuumed table table=pending_objects17732026/08/27 09:28:24 INFO Vacuumed table table=multipart_uploads17742026/08/27 09:28:24 INFO Vacuumed table table=closures17752026/08/27 09:28:25 INFO Vacuumed table table=objects17762026/08/27 09:28:25 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"17772026/08/27 09:28:26 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=01778=== NAME TestPinProtectsFromGC1779 client_integration_test.go:709: Pin successfully protected closure from garbage collection17802026/08/27 09:28:26 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: sending request: request failed after retries: Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused"1781--- PASS: TestPinProtectsFromGC (6.13s)17822026/08/27 09:28:26 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures17832026/08/27 09:28:26 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=197.409337ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures17842026/08/27 09:28:26 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=410.601415ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures17852026/08/27 09:28:26 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=01786=== NAME TestClientIntegration1787 client_integration_test.go:303: Objects in database after GC:1788 client_integration_test.go:303: Successfully deleted all objects with GC --force1789--- PASS: TestClientIntegration (4.63s)17902026/08/27 09:28:27 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=816.847038ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures1791=== NAME TestOrphanedObjectsGCStressTest1792 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains1793 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion1794 orphaned_objects_gc_test.go:509: Stress test completed successfully:1795 orphaned_objects_gc_test.go:510: - Active objects preserved: 201796 orphaned_objects_gc_test.go:511: - Objects deleted: 2101797 orphaned_objects_gc_test.go:512: - Total GC'd: 2101798--- PASS: TestOrphanedObjectsGCStressTest (10.31s)17992026/08/27 09:28:27 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.616981701s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures1800--- PASS: TestClientErrorHandling (0.00s)1801 --- PASS: TestClientErrorHandling/InvalidStorePath (2.09s)1802 --- PASS: TestClientErrorHandling/InvalidAuthToken (2.18s)1803 --- PASS: TestClientErrorHandling/ServerNotAvailable (6.80s)1804PASS1805{"timestamp":"2026-08-27T09:28:29.525047Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:50643","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(9)"}18062026-08-27 09:28:29.630 UTC [13673] LOG: received smart shutdown request18072026-08-27 09:28:29.631 UTC [13673] LOG: background worker "logical replication launcher" (PID 13683) exited with exit code 118082026-08-27 09:28:29.639 UTC [13678] LOG: shutting down18092026-08-27 09:28:29.639 UTC [13678] LOG: checkpoint starting: shutdown immediate18102026-08-27 09:28:30.684 UTC [13678] LOG: checkpoint complete: wrote 13511 buffers (82.5%), wrote 3 SLRU buffers; 0 WAL file(s) added, 0 removed, 13 recycled; write=0.787 s, sync=0.257 s, total=1.046 s; sync files=15167, longest=0.001 s, average=0.001 s; distance=212547 kB, estimate=212547 kB; lsn=0/E71BEE8, redo lsn=0/E71BEE818112026-08-27 09:28:30.689 UTC [13673] LOG: database system is shut down1812Running OIDC tests...1813=== RUN TestGlobMatch1814=== PAUSE TestGlobMatch1815=== RUN TestAudienceForIssuer1816=== PAUSE TestAudienceForIssuer1817=== RUN TestValidateToken_ValidToken1818=== PAUSE TestValidateToken_ValidToken1819=== RUN TestValidateToken_WrongAudience1820=== PAUSE TestValidateToken_WrongAudience1821=== RUN TestValidateToken_Expired1822=== PAUSE TestValidateToken_Expired1823=== RUN TestValidateToken_BoundClaimsMismatch1824=== PAUSE TestValidateToken_BoundClaimsMismatch1825=== RUN TestValidateToken_BoundSubjectMismatch1826=== PAUSE TestValidateToken_BoundSubjectMismatch1827=== RUN TestValidateToken_MultipleProviders1828=== PAUSE TestValidateToken_MultipleProviders1829=== RUN TestValidateToken_NoMatchingProvider1830=== PAUSE TestValidateToken_NoMatchingProvider1831=== CONT TestGlobMatch1832=== RUN TestGlobMatch/foo_foo1833=== PAUSE TestGlobMatch/foo_foo1834=== CONT TestValidateToken_MultipleProviders1835=== CONT TestValidateToken_ValidToken1836=== CONT TestValidateToken_Expired1837=== CONT TestValidateToken_WrongAudience1838=== RUN TestGlobMatch/foo_bar1839=== PAUSE TestGlobMatch/foo_bar1840=== RUN TestGlobMatch/*_1841=== PAUSE TestGlobMatch/*_1842=== RUN TestGlobMatch/*_anything1843=== PAUSE TestGlobMatch/*_anything1844=== RUN TestGlobMatch/foo*_foo1845=== CONT TestValidateToken_BoundSubjectMismatch1846=== PAUSE TestGlobMatch/foo*_foo1847=== RUN TestGlobMatch/foo*_foobar1848=== PAUSE TestGlobMatch/foo*_foobar1849=== RUN TestGlobMatch/foo*_bar1850=== PAUSE TestGlobMatch/foo*_bar1851=== RUN TestGlobMatch/*bar_bar1852=== PAUSE TestGlobMatch/*bar_bar1853=== CONT TestValidateToken_BoundClaimsMismatch1854=== CONT TestAudienceForIssuer1855--- PASS: TestAudienceForIssuer (0.00s)1856=== CONT TestValidateToken_NoMatchingProvider1857=== RUN TestGlobMatch/*bar_foobar1858=== PAUSE TestGlobMatch/*bar_foobar1859=== RUN TestGlobMatch/*bar_foo1860=== PAUSE TestGlobMatch/*bar_foo1861=== RUN TestGlobMatch/foo*bar_foobar1862=== PAUSE TestGlobMatch/foo*bar_foobar1863=== RUN TestGlobMatch/foo*bar_foo123bar1864=== PAUSE TestGlobMatch/foo*bar_foo123bar1865=== RUN TestGlobMatch/foo*bar_foobarbaz1866=== PAUSE TestGlobMatch/foo*bar_foobarbaz1867=== RUN TestGlobMatch/*/*_foo/bar1868=== PAUSE TestGlobMatch/*/*_foo/bar1869=== RUN TestGlobMatch/*/*_foo1870=== PAUSE TestGlobMatch/*/*_foo1871=== RUN TestGlobMatch/refs/heads/*_refs/heads/main1872=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main1873=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.01874=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.01875=== RUN TestGlobMatch/refs/*/main_refs/heads/main1876=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main1877=== RUN TestGlobMatch/fo?_foo1878=== PAUSE TestGlobMatch/fo?_foo1879=== RUN TestGlobMatch/fo?_fo1880=== PAUSE TestGlobMatch/fo?_fo1881=== RUN TestGlobMatch/fo?_fooo1882=== PAUSE TestGlobMatch/fo?_fooo1883=== RUN TestGlobMatch/?oo_foo1884=== PAUSE TestGlobMatch/?oo_foo1885=== RUN TestGlobMatch/?oo_boo1886=== PAUSE TestGlobMatch/?oo_boo1887=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main1888=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main1889=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main1890=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main1891=== CONT TestGlobMatch/foo_foo1892=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main1893=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main1894=== CONT TestGlobMatch/?oo_boo1895=== CONT TestGlobMatch/?oo_foo1896=== CONT TestGlobMatch/fo?_fooo1897=== CONT TestGlobMatch/fo?_fo1898=== CONT TestGlobMatch/fo?_foo1899=== CONT TestGlobMatch/refs/*/main_refs/heads/main1900=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.01901=== CONT TestGlobMatch/refs/heads/*_refs/heads/main1902=== CONT TestGlobMatch/*/*_foo1903=== CONT TestGlobMatch/*/*_foo/bar1904=== CONT TestGlobMatch/foo*bar_foobarbaz1905=== CONT TestGlobMatch/foo*bar_foo123bar1906=== CONT TestGlobMatch/foo*bar_foobar1907=== CONT TestGlobMatch/*bar_foo1908=== CONT TestGlobMatch/*bar_foobar1909=== CONT TestGlobMatch/*bar_bar1910=== CONT TestGlobMatch/foo*_bar1911=== CONT TestGlobMatch/foo*_foobar1912=== CONT TestGlobMatch/foo*_foo1913=== CONT TestGlobMatch/foo_bar1914=== CONT TestGlobMatch/*_anything1915=== CONT TestGlobMatch/*_1916--- PASS: TestGlobMatch (0.00s)1917 --- PASS: TestGlobMatch/foo_foo (0.00s)1918 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)1919 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)1920 --- PASS: TestGlobMatch/?oo_boo (0.00s)1921 --- PASS: TestGlobMatch/?oo_foo (0.00s)1922 --- PASS: TestGlobMatch/fo?_fooo (0.00s)1923 --- PASS: TestGlobMatch/fo?_fo (0.00s)1924 --- PASS: TestGlobMatch/fo?_foo (0.00s)1925 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)1926 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)1927 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)1928 --- PASS: TestGlobMatch/*/*_foo (0.00s)1929 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)1930 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)1931 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)1932 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)1933 --- PASS: TestGlobMatch/*bar_foo (0.00s)1934 --- PASS: TestGlobMatch/*bar_foobar (0.00s)1935 --- PASS: TestGlobMatch/*bar_bar (0.00s)1936 --- PASS: TestGlobMatch/foo*_bar (0.00s)1937 --- PASS: TestGlobMatch/foo*_foobar (0.00s)1938 --- PASS: TestGlobMatch/foo*_foo (0.00s)1939 --- PASS: TestGlobMatch/foo_bar (0.00s)1940 --- PASS: TestGlobMatch/*_anything (0.00s)1941 --- PASS: TestGlobMatch/*_ (0.00s)19422026/08/27 09:28:31 INFO OIDC provider initialized name=test19432026/08/27 09:28:31 INFO OIDC provider initialized name=test19442026/08/27 09:28:31 INFO OIDC provider initialized name=provider119452026/08/27 09:28:31 INFO OIDC provider initialized name=test19462026/08/27 09:28:31 INFO OIDC provider initialized name=test19472026/08/27 09:28:31 INFO OIDC provider initialized name=provider119482026/08/27 09:28:31 INFO OIDC provider initialized name=test19492026/08/27 09:28:31 INFO OIDC provider initialized name=provider21950--- PASS: TestValidateToken_BoundSubjectMismatch (0.01s)1951--- PASS: TestValidateToken_WrongAudience (0.01s)1952--- PASS: TestValidateToken_ValidToken (0.01s)1953--- PASS: TestValidateToken_NoMatchingProvider (0.01s)1954--- PASS: TestValidateToken_Expired (0.01s)1955--- PASS: TestValidateToken_BoundClaimsMismatch (0.01s)1956--- PASS: TestValidateToken_MultipleProviders (0.01s)1957PASS1958Running hook tests...1959=== RUN TestSendPathsEmpty1960=== PAUSE TestSendPathsEmpty1961=== RUN TestQueueEnqueueAndFetch1962=== PAUSE TestQueueEnqueueAndFetch1963=== RUN TestQueueDeduplication1964=== PAUSE TestQueueDeduplication1965=== RUN TestQueueRemove1966=== PAUSE TestQueueRemove1967=== RUN TestQueueFetchBatchLimit1968=== PAUSE TestQueueFetchBatchLimit1969=== RUN TestQueueRetryMovesToBack1970=== PAUSE TestQueueRetryMovesToBack1971=== RUN TestQueueFetchRemoveLifecycle1972=== PAUSE TestQueueFetchRemoveLifecycle1973=== RUN TestQueueConcurrentWriters1974=== PAUSE TestQueueConcurrentWriters1975=== RUN TestQueueRemoveLargeClosure1976=== PAUSE TestQueueRemoveLargeClosure1977=== RUN TestServerClientIntegration1978=== PAUSE TestServerClientIntegration1979=== RUN TestServerQueueError1980=== PAUSE TestServerQueueError1981=== RUN TestGetListenerSocketActivation1982 server_test.go:210: === RUN TestGetListenerSocketActivation1983 --- PASS: TestGetListenerSocketActivation (0.00s)1984 PASS1985 1986--- PASS: TestGetListenerSocketActivation (0.01s)1987=== RUN TestDrainIsolatesPoisonPath1988=== PAUSE TestDrainIsolatesPoisonPath1989=== RUN TestRunNotBlockedByPoisonHead1990=== PAUSE TestRunNotBlockedByPoisonHead1991=== RUN TestDrainGivesUpWhenServerDown1992=== PAUSE TestDrainGivesUpWhenServerDown1993=== RUN TestFailedPathPrunedByLaterClosure1994=== PAUSE TestFailedPathPrunedByLaterClosure1995=== RUN TestWorkerUploadsAndRemoves1996=== PAUSE TestWorkerUploadsAndRemoves1997=== RUN TestWorkerSkipsGCdPaths1998=== PAUSE TestWorkerSkipsGCdPaths1999=== RUN TestWorkerPrunesClosureDeps2000=== PAUSE TestWorkerPrunesClosureDeps2001=== CONT TestSendPathsEmpty2002=== CONT TestServerClientIntegration2003=== CONT TestQueueRemove2004=== CONT TestQueueRetryMovesToBack2005--- PASS: TestSendPathsEmpty (0.00s)2006=== CONT TestQueueDeduplication2007=== CONT TestQueueEnqueueAndFetch2008=== CONT TestFailedPathPrunedByLaterClosure2009=== CONT TestWorkerPrunesClosureDeps2010=== CONT TestWorkerSkipsGCdPaths2011=== CONT TestQueueConcurrentWriters2012=== CONT TestQueueFetchBatchLimit2013--- PASS: TestServerClientIntegration (0.00s)2014=== CONT TestWorkerUploadsAndRemoves2015--- PASS: TestQueueEnqueueAndFetch (0.01s)2016=== CONT TestQueueFetchRemoveLifecycle2017--- PASS: TestQueueDeduplication (0.01s)2018=== CONT TestRunNotBlockedByPoisonHead20192026/08/27 09:28:31 INFO Uploading batch count=120202026/08/27 09:28:31 ERROR Upload failed error="upload failed" count=12021--- PASS: TestQueueFetchBatchLimit (0.01s)2022=== CONT TestDrainGivesUpWhenServerDown20232026/08/27 09:28:31 INFO Upload queue status pending=220242026/08/27 09:28:31 INFO Uploading batch count=120252026/08/27 09:28:31 INFO Upload queue status pending=220262026/08/27 09:28:31 INFO Uploading batch count=22027--- PASS: TestQueueRemove (0.01s)2028=== CONT TestQueueRemoveLargeClosure20292026/08/27 09:28:31 INFO Upload queue status pending=220302026/08/27 09:28:31 WARN Store path no longer exists (garbage collected?), removing from queue path=/nix/var/nix/builds/nix-13638-4044143606/TestWorkerSkipsGCdPaths2596114502/002/nonexistent20312026/08/27 09:28:31 INFO Uploading batch count=120322026/08/27 09:28:31 INFO Uploading batch count=120332026/08/27 09:28:31 INFO Uploading batch count=12034--- PASS: TestQueueRetryMovesToBack (0.01s)2035=== CONT TestDrainIsolatesPoisonPath2036--- PASS: TestQueueFetchRemoveLifecycle (0.00s)2037=== CONT TestServerQueueError20382026/08/27 09:28:31 INFO Upload queue status pending=32039--- PASS: TestFailedPathPrunedByLaterClosure (0.01s)20402026/08/27 09:28:31 ERROR Failed to queue paths error="permission denied" count=120412026/08/27 09:28:31 INFO Uploading batch count=120422026/08/27 09:28:31 ERROR Upload failed error="upload failed" count=12043--- PASS: TestServerQueueError (0.00s)20442026/08/27 09:28:31 INFO Uploading batch count=220452026/08/27 09:28:31 ERROR Upload failed error="upload failed" count=220462026/08/27 09:28:31 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-13638-4044143606/TestDrainGivesUpWhenServerDown1884484541/002/a20472026/08/27 09:28:31 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-13638-4044143606/TestDrainGivesUpWhenServerDown1884484541/002/b20482026/08/27 09:28:31 INFO Uploading batch count=220492026/08/27 09:28:31 ERROR Upload failed error="upload failed" count=220502026/08/27 09:28:31 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-13638-4044143606/TestDrainGivesUpWhenServerDown1884484541/002/c20512026/08/27 09:28:31 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-13638-4044143606/TestDrainGivesUpWhenServerDown1884484541/002/d20522026/08/27 09:28:31 INFO Uploading batch count=220532026/08/27 09:28:31 ERROR Upload failed error="upload failed" count=220542026/08/27 09:28:31 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-13638-4044143606/TestDrainGivesUpWhenServerDown1884484541/002/e20552026/08/27 09:28:31 INFO Uploading batch count=420562026/08/27 09:28:31 ERROR Upload failed error="upload failed" count=420572026/08/27 09:28:31 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-13638-4044143606/TestDrainGivesUpWhenServerDown1884484541/002/f20582026/08/27 09:28:31 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-13638-4044143606/TestDrainIsolatesPoisonPath3832613598/002/bbb20592026/08/27 09:28:31 ERROR Drain finished with paths left in queue remaining=1020602026/08/27 09:28:31 INFO Uploading batch count=120612026/08/27 09:28:31 ERROR Upload failed error="upload failed" count=120622026/08/27 09:28:31 INFO Uploading batch count=120632026/08/27 09:28:31 ERROR Upload failed error="upload failed" count=120642026/08/27 09:28:31 INFO Uploading batch count=120652026/08/27 09:28:31 ERROR Upload failed error="upload failed" count=120662026/08/27 09:28:31 ERROR Drain finished with paths left in queue remaining=12067--- PASS: TestDrainGivesUpWhenServerDown (0.01s)2068--- PASS: TestDrainIsolatesPoisonPath (0.01s)2069--- PASS: TestWorkerPrunesClosureDeps (0.03s)2070--- PASS: TestWorkerUploadsAndRemoves (0.03s)2071--- PASS: TestWorkerSkipsGCdPaths (0.03s)2072--- PASS: TestQueueRemoveLargeClosure (0.05s)2073--- PASS: TestQueueConcurrentWriters (0.07s)20742026/08/27 09:28:32 INFO Uploading batch count=120752026/08/27 09:28:32 INFO Uploading batch count=120762026/08/27 09:28:32 INFO Uploading batch count=120772026/08/27 09:28:32 ERROR Upload failed error="upload failed" count=120782026/08/27 09:28:32 INFO Uploading batch count=120792026/08/27 09:28:32 ERROR Upload failed error="upload failed" count=120802026/08/27 09:28:32 INFO Uploading batch count=120812026/08/27 09:28:32 ERROR Upload failed error="upload failed" count=120822026/08/27 09:28:32 INFO Uploading batch count=120832026/08/27 09:28:32 ERROR Upload failed error="upload failed" count=120842026/08/27 09:28:32 ERROR Drain finished with paths left in queue remaining=12085--- PASS: TestRunNotBlockedByPoisonHead (1.01s)2086PASS