niks3-go-unit-tests
default.checks.x86_64-linux.go-unit-tests
· build #127
· raw
1tribuchet: building on jamie2Running client tests...3=== RUN TestDoServerRequestAttachesToken4=== PAUSE TestDoServerRequestAttachesToken5=== RUN TestCaseHackSuffix6=== PAUSE TestCaseHackSuffix7=== RUN TestFilterOversizedClosures8=== PAUSE TestFilterOversizedClosures9=== RUN TestPartSizeForNAR10=== PAUSE TestPartSizeForNAR11=== RUN TestUploadMultipart_SupersededByPeer12=== PAUSE TestUploadMultipart_SupersededByPeer13=== RUN TestDumpPathMatchesNix14=== PAUSE TestDumpPathMatchesNix15=== RUN TestDumpPathSingleFile16=== PAUSE TestDumpPathSingleFile17=== RUN TestDumpPathWriterError18=== PAUSE TestDumpPathWriterError19=== RUN TestEncodeNixBase3220=== PAUSE TestEncodeNixBase3221=== RUN TestEncodeNixBase32WithRealHash22=== PAUSE TestEncodeNixBase32WithRealHash23=== RUN TestConvertHashToNix3224=== PAUSE TestConvertHashToNix3225=== RUN TestGetStorePathHash26=== PAUSE TestGetStorePathHash27=== RUN TestPathInfoHashCompatibility28=== PAUSE TestPathInfoHashCompatibility29=== RUN TestParsePathInfoJSON30=== PAUSE TestParsePathInfoJSON31=== RUN TestParsePathInfoJSONMultiplePaths32=== PAUSE TestParsePathInfoJSONMultiplePaths33=== RUN TestPathInfoCACompatibility34=== PAUSE TestPathInfoCACompatibility35=== RUN TestRateLimiterFeedback36=== PAUSE TestRateLimiterFeedback37=== RUN TestRateLimiterFeedback_400DoesNotCountAsSuccess38=== PAUSE TestRateLimiterFeedback_400DoesNotCountAsSuccess39=== RUN TestResolveStorePath40=== PAUSE TestResolveStorePath41=== RUN TestDoWithRetry_BodyReplayedViaGetBody42=== PAUSE TestDoWithRetry_BodyReplayedViaGetBody43=== RUN TestShellSplit44=== PAUSE TestShellSplit45=== RUN TestShellSplitErrors46=== PAUSE TestShellSplitErrors47=== RUN TestSetClientTLS48=== PAUSE TestSetClientTLS49=== RUN TestSetClientTLSDoesNotMutateDefaultTransport50=== PAUSE TestSetClientTLSDoesNotMutateDefaultTransport51=== RUN TestSetClientTLSErrors52=== PAUSE TestSetClientTLSErrors53=== RUN TestStaticToken54=== PAUSE TestStaticToken55=== RUN TestFileTokenReadsAndCaches56=== PAUSE TestFileTokenReadsAndCaches57=== RUN TestFileTokenMissing58=== PAUSE TestFileTokenMissing59=== RUN TestFileTokenEmpty60=== PAUSE TestFileTokenEmpty61=== RUN TestScriptTokenNoExpiryRerunsEveryCall62=== PAUSE TestScriptTokenNoExpiryRerunsEveryCall63=== RUN TestScriptTokenCachesUntilRefresh64=== PAUSE TestScriptTokenCachesUntilRefresh65=== RUN TestScriptTokenEmptyToken66=== PAUSE TestScriptTokenEmptyToken67=== RUN TestScriptTokenBadJSON68=== PAUSE TestScriptTokenBadJSON69=== RUN TestScriptTokenScriptFails70=== PAUSE TestScriptTokenScriptFails71=== RUN TestScriptTokenEmptyCommand72=== PAUSE TestScriptTokenEmptyCommand73=== CONT TestDoServerRequestAttachesToken74=== CONT TestResolveStorePath75=== CONT TestFileTokenMissing76=== CONT TestSetClientTLSDoesNotMutateDefaultTransport77=== CONT TestStaticToken78=== CONT TestScriptTokenNoExpiryRerunsEveryCall79--- PASS: TestFileTokenMissing (0.00s)80--- PASS: TestStaticToken (0.00s)81--- PASS: TestResolveStorePath (0.00s)82=== CONT TestDumpPathMatchesNix83=== CONT TestPathInfoCACompatibility84=== RUN TestPathInfoCACompatibility/null_ca_field85=== PAUSE TestPathInfoCACompatibility/null_ca_field86=== RUN TestPathInfoCACompatibility/old_string_format_-_text87=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text88=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive89=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive90=== RUN TestPathInfoCACompatibility/new_structured_format_-_text91=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text92=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method93=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method94=== CONT TestPathInfoCACompatibility/null_ca_field95=== CONT TestEncodeNixBase32WithRealHash96=== CONT TestUploadMultipart_SupersededByPeer97=== RUN TestUploadMultipart_SupersededByPeer/exists98=== PAUSE TestUploadMultipart_SupersededByPeer/exists99=== RUN TestUploadMultipart_SupersededByPeer/missing100=== PAUSE TestUploadMultipart_SupersededByPeer/missing101=== CONT TestUploadMultipart_SupersededByPeer/exists102--- PASS: TestEncodeNixBase32WithRealHash (0.00s)103=== CONT TestGetStorePathHash104=== CONT TestDumpPathSingleFile105=== CONT TestFileTokenReadsAndCaches106=== CONT TestScriptTokenScriptFails107=== CONT TestScriptTokenBadJSON108=== CONT TestScriptTokenEmptyToken109=== CONT TestScriptTokenCachesUntilRefresh110=== CONT TestScriptTokenEmptyCommand111=== CONT TestShellSplitErrors112=== CONT TestSetClientTLS113=== CONT TestShellSplit114=== CONT TestDoWithRetry_BodyReplayedViaGetBody115=== CONT TestDumpPathWriterError116=== CONT TestEncodeNixBase32117=== CONT TestParsePathInfoJSONMultiplePaths118=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess119=== CONT TestRateLimiterFeedback120=== CONT TestParsePathInfoJSON121=== RUN TestGetStorePathHash/valid_store_path122=== CONT TestPathInfoHashCompatibility123=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)124=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)125=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon126=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon127=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI128=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI129=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512130=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512131=== CONT TestFileTokenEmpty132--- PASS: TestScriptTokenEmptyCommand (0.00s)133=== CONT TestSetClientTLSErrors134--- PASS: TestShellSplitErrors (0.00s)135--- PASS: TestFileTokenReadsAndCaches (0.00s)136=== CONT TestFilterOversizedClosures137=== RUN TestFilterOversizedClosures/no_limit_keeps_everything138=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything139=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped140=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped141--- PASS: TestFileTokenEmpty (0.00s)142=== RUN TestFilterOversizedClosures/all_closures_skipped143=== PAUSE TestFilterOversizedClosures/all_closures_skipped144=== RUN TestEncodeNixBase32/test_string_hash145=== PAUSE TestEncodeNixBase32/test_string_hash146=== RUN TestEncodeNixBase32/empty_input147=== PAUSE TestEncodeNixBase32/empty_input148=== CONT TestPathInfoCACompatibility/new_structured_format_-_text149=== RUN TestRateLimiterFeedback/429_enables_limiter150=== CONT TestPathInfoCACompatibility/old_string_format_-_text151=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method152=== RUN TestParsePathInfoJSON/Nix_format1532026/08/06 11:09:51 WARN Rate limiter enabled after throttle name=server-test rate=5154=== PAUSE TestParsePathInfoJSON/Nix_format155=== PAUSE TestGetStorePathHash/valid_store_path156=== PAUSE TestRateLimiterFeedback/429_enables_limiter157=== RUN TestParsePathInfoJSON/Lix_format158=== PAUSE TestParsePathInfoJSON/Lix_format159=== CONT TestConvertHashToNix32160=== RUN TestConvertHashToNix32/SRI_format_to_Nix32161=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32162=== CONT TestUploadMultipart_SupersededByPeer/missing163--- PASS: TestShellSplit (0.00s)164=== CONT TestPartSizeForNAR165=== RUN TestPartSizeForNAR/zero_stays_at_minimum166=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum167=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths168=== CONT TestCaseHackSuffix169=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive170=== RUN TestPartSizeForNAR/small_stays_at_minimum171=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)172=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512173=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths174=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon175=== RUN TestGetStorePathHash/basename_without_hyphen_should_error176=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error177=== RUN TestRateLimiterFeedback/503_enables_limiter178=== RUN TestParsePathInfoJSON/empty_input179=== RUN TestSetClientTLSErrors/missing_cert_file180=== RUN TestConvertHashToNix32/already_Nix32_format181--- PASS: TestDoServerRequestAttachesToken (0.01s)182=== PAUSE TestPartSizeForNAR/small_stays_at_minimum183=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI184=== CONT TestFilterOversizedClosures/no_limit_keeps_everything185=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths186=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths1872026/08/06 11:09:51 WARN Rate limiter enabled after throttle name=server-test rate=5188=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths189--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.01s)1902026/08/06 11:09:51 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:34533191=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum192=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error193=== CONT TestEncodeNixBase32/empty_input194=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error195=== CONT TestEncodeNixBase32/test_string_hash196=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error197=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error198=== PAUSE TestRateLimiterFeedback/503_enables_limiter199=== PAUSE TestParsePathInfoJSON/empty_input200=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter201=== RUN TestParsePathInfoJSON/whitespace_only202=== PAUSE TestParsePathInfoJSON/whitespace_only203=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter204=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter2052026/08/06 11:09:51 WARN Rate limiter backed off name=server-test rate=5206=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter2072026/08/06 11:09:51 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:34533208=== CONT TestFilterOversizedClosures/all_closures_skipped2092026/08/06 11:09:51 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=50210=== RUN TestSetClientTLS/rejects_connection_without_client_cert211=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert212=== PAUSE TestSetClientTLSErrors/missing_cert_file213=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped214=== RUN TestSetClientTLSErrors/missing_key_file2152026/08/06 11:09:51 WARN Skipping closure: path exceeds server max NAR size top_level_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper oversized_path=/nix/store/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb-vm-image nar_size=5000 max_nar_size=2000216=== PAUSE TestSetClientTLSErrors/missing_key_file217=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths218=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum219=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts220=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts221=== RUN TestPartSizeForNAR/1_TiB222--- PASS: TestScriptTokenScriptFails (0.00s)223=== CONT TestGetStorePathHash/valid_store_path224--- PASS: TestScriptTokenBadJSON (0.01s)225--- PASS: TestScriptTokenEmptyToken (0.01s)226=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error227=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error228=== CONT TestGetStorePathHash/basename_without_hyphen_should_error229=== PAUSE TestConvertHashToNix32/already_Nix32_format230=== RUN TestParsePathInfoJSON/invalid_JSON231=== CONT TestRateLimiterFeedback/429_enables_limiter232=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter233=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter234=== CONT TestRateLimiterFeedback/503_enables_limiter235=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA236=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA237=== RUN TestSetClientTLSErrors/missing_ca_file238=== PAUSE TestSetClientTLSErrors/missing_ca_file239=== PAUSE TestPartSizeForNAR/1_TiB240=== RUN TestPartSizeForNAR/5_TiB_S3_max_object241=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object242=== RUN TestPartSizeForNAR/capped_at_5_GiB243--- PASS: TestUploadMultipart_SupersededByPeer (0.00s)244 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.01s)245 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.01s)246--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.01s)247--- PASS: TestPathInfoCACompatibility (0.00s)248 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)249 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)250 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)251 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)252 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)253=== RUN TestConvertHashToNix32/invalid_format254=== PAUSE TestConvertHashToNix32/invalid_format255=== PAUSE TestParsePathInfoJSON/invalid_JSON2562026/08/06 11:09:51 WARN Rate limiter enabled after throttle name=server-test rate=5257=== RUN TestSetClientTLS/preserves_debug_logging_transport2582026/08/06 11:09:51 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:36301259=== PAUSE TestSetClientTLS/preserves_debug_logging_transport2602026/08/06 11:09:51 WARN Rate limiter enabled after throttle name=server-test rate=5261=== RUN TestSetClientTLSErrors/invalid_ca_file2622026/08/06 11:09:51 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:37511263=== PAUSE TestPartSizeForNAR/capped_at_5_GiB264=== CONT TestPartSizeForNAR/zero_stays_at_minimum265--- PASS: TestPathInfoHashCompatibility (0.00s)266 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)267 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)268 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)269 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)270--- PASS: TestGetStorePathHash (0.01s)271 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)272 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)273 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)274 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)275=== CONT TestConvertHashToNix32/SRI_format_to_Nix32276--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.01s)277--- PASS: TestEncodeNixBase32 (0.00s)278 --- PASS: TestEncodeNixBase32/empty_input (0.00s)279 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)2802026/08/06 11:09:51 WARN Rate limiter backed off name=server-test rate=5281=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts282=== CONT TestPartSizeForNAR/small_stays_at_minimum283=== CONT TestConvertHashToNix32/invalid_format2842026/08/06 11:09:51 WARN Rate limiter backed off name=server-test rate=5285--- PASS: TestFilterOversizedClosures (0.00s)286 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)287 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)288 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)289--- PASS: TestParsePathInfoJSONMultiplePaths (0.01s)290 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)291 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)292=== CONT TestConvertHashToNix32/already_Nix32_format293--- PASS: TestRateLimiterFeedback (0.01s)294 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)295 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)296 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)297 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)298--- PASS: TestConvertHashToNix32 (0.01s)299 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)300 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)301 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)302=== CONT TestParsePathInfoJSON/whitespace_only303=== CONT TestParsePathInfoJSON/Nix_format304=== CONT TestParsePathInfoJSON/invalid_JSON305=== CONT TestParsePathInfoJSON/empty_input306=== CONT TestParsePathInfoJSON/Lix_format307--- PASS: TestParsePathInfoJSON (0.01s)308 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)309 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)310 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)311 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)312 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)313=== CONT TestSetClientTLS/rejects_connection_without_client_cert314=== CONT TestSetClientTLS/preserves_debug_logging_transport315=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA316=== PAUSE TestSetClientTLSErrors/invalid_ca_file317=== CONT TestSetClientTLSErrors/missing_cert_file318=== CONT TestPartSizeForNAR/1_TiB319=== CONT TestPartSizeForNAR/capped_at_5_GiB320=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum321=== CONT TestPartSizeForNAR/5_TiB_S3_max_object322=== CONT TestSetClientTLSErrors/missing_ca_file323--- PASS: TestPartSizeForNAR (0.01s)324 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)325 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)326 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)327 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)328 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)329 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)330 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)331=== CONT TestSetClientTLSErrors/invalid_ca_file332=== CONT TestSetClientTLSErrors/missing_key_file333--- PASS: TestSetClientTLSErrors (0.01s)334 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)335 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)336 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)337 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)338--- PASS: TestScriptTokenCachesUntilRefresh (0.01s)3392026/08/06 11:09:51 http: TLS handshake error from 127.0.0.1:47366: remote error: tls: bad certificate340--- PASS: TestSetClientTLS (0.01s)341 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.00s)342 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.00s)343 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.01s)344--- PASS: TestDumpPathWriterError (0.03s)345--- PASS: TestDumpPathSingleFile (0.04s)346--- PASS: TestCaseHackSuffix (0.03s)347--- PASS: TestDumpPathMatchesNix (0.07s)348--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)349PASS350Running server tests...351The files belonging to this database system will be owned by user "nixbld".352This user must also own the server process.353354The database cluster will be initialized with locale "C".355The default database encoding has accordingly been set to "SQL_ASCII".356The default text search configuration will be set to "english".357358Data page checksums are enabled.359360creating directory /build/postgres4127384062/data ... ok361creating subdirectories ... ok362selecting dynamic shared memory implementation ... posix363selecting default "max_connections" ... 100364selecting default "shared_buffers" ... 128MB365selecting default time zone ... UTC366creating configuration files ... ok367running bootstrap script ... ok368performing post-bootstrap initialization ... ok369syncing data to disk ... ok370371initdb: warning: enabling "trust" authentication for local connections372initdb: 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.373374Success. You can now start the database server using:375376 pg_ctl -D /build/postgres4127384062/data -l logfile start377378/build/postgres4127384062:5432 - no response3792026-08-06 11:09:53.363 UTC [113] LOG: starting PostgreSQL 18.4 on x86_64-pc-linux-gnu, compiled by clang version 21.1.8, 64-bit3802026-08-06 11:09:53.364 UTC [113] LOG: listening on Unix socket "/build/postgres4127384062/.s.PGSQL.5432"3812026-08-06 11:09:53.370 UTC [120] LOG: database system was shut down at 2026-08-06 11:09:53 UTC3822026-08-06 11:09:53.373 UTC [113] LOG: database system is ready to accept connections383/build/postgres4127384062:5432 - accepting connections384=== RUN TestService_AuthMiddleware385=== PAUSE TestService_AuthMiddleware386=== RUN TestService_AuthMiddleware_MTLSProxyHeader387=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader388=== RUN TestService_AuthMiddleware_MTLSBoundSubjects389=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects390=== RUN TestService_ReadAuthMiddleware391=== PAUSE TestService_ReadAuthMiddleware392=== RUN TestService_AuthMiddleware_OIDC393=== PAUSE TestService_AuthMiddleware_OIDC394=== RUN TestCacheConfigHandler395=== PAUSE TestCacheConfigHandler396=== RUN TestCacheStatsHandler397=== PAUSE TestCacheStatsHandler398=== RUN TestClientCADerivations399=== PAUSE TestClientCADerivations400=== RUN TestClientErrorHandling401=== PAUSE TestClientErrorHandling402=== RUN TestClientIntegration403=== PAUSE TestClientIntegration404=== RUN TestClientMultipleUploads405=== PAUSE TestClientMultipleUploads406=== RUN TestClientWithDependencies407=== PAUSE TestClientWithDependencies408=== RUN TestPinProtectsFromGC409=== PAUSE TestPinProtectsFromGC410=== RUN TestGCAdvisoryLockBlocksConcurrentRun4112026-08-06 11:09:53.839 UTC [908] ERROR: relation "goose_db_version" does not exist at character 364122026-08-06 11:09:53.839 UTC [908] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC4132026/08/06 11:09:53 OK 20241026095416_initial_model.sql (7.94ms)4142026/08/06 11:09:53 OK 20251210153512_drop_unused_gin_index.sql (1.06ms)4152026/08/06 11:09:53 OK 20251218171726_add_pins.sql (1.69ms)4162026/08/06 11:09:53 OK 20260628120000_add_object_size_and_stats.sql (1.89ms)4172026/08/06 11:09:53 goose: successfully migrated database to version: 202606281200004182026/08/06 11:09:53 OK 1_commit_pending_closure.sql (1.79ms)4192026/08/06 11:09:53 OK 2_object_stats_trigger.sql (1.4ms)4202026/08/06 11:09:53 goose: up to current file version: 2421--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.12s)422=== RUN TestGCBugBareHashReferences423=== PAUSE TestGCBugBareHashReferences424=== RUN TestGCMetrics425=== PAUSE TestGCMetrics426=== RUN TestGCTaskStore_StartNew427=== PAUSE TestGCTaskStore_StartNew428=== RUN TestGCTaskStore_DeduplicateSameParams429=== PAUSE TestGCTaskStore_DeduplicateSameParams430=== RUN TestGCTaskStore_ConflictDifferentParams431=== PAUSE TestGCTaskStore_ConflictDifferentParams432=== RUN TestGCTaskStore_GetEmpty433=== PAUSE TestGCTaskStore_GetEmpty434=== RUN TestGCTaskStore_GetReturnsLatest435=== PAUSE TestGCTaskStore_GetReturnsLatest436=== RUN TestGCTaskStore_CompletedAllowsNewTask437=== PAUSE TestGCTaskStore_CompletedAllowsNewTask438=== RUN TestGCTaskStore_PhaseUpdates439=== PAUSE TestGCTaskStore_PhaseUpdates440=== RUN TestGCTaskStore_Fail441=== PAUSE TestGCTaskStore_Fail442=== RUN TestGracefulShutdownDrainsInflight443=== PAUSE TestGracefulShutdownDrainsInflight444=== RUN TestService_healthCheckHandler445=== PAUSE TestService_healthCheckHandler446=== RUN TestGenerateLandingPage447=== PAUSE TestGenerateLandingPage448=== RUN TestCacheConfigHandlerMaxNarSize449=== PAUSE TestCacheConfigHandlerMaxNarSize450=== RUN TestCreatePendingClosureRejectsOversizedNAR451=== PAUSE TestCreatePendingClosureRejectsOversizedNAR452=== RUN TestNARDeduplicationMetadataUploadBug453=== PAUSE TestNARDeduplicationMetadataUploadBug454=== RUN TestMetricsInventory455=== PAUSE TestMetricsInventory456=== RUN TestService_NativeMTLS457=== PAUSE TestService_NativeMTLS458=== RUN TestServerTLSConfig459=== PAUSE TestServerTLSConfig460=== RUN TestMultipartCleanup461=== PAUSE TestMultipartCleanup462=== RUN TestObjectStatsTrigger463=== PAUSE TestObjectStatsTrigger464=== RUN TestOrphanedObjectsGC465=== PAUSE TestOrphanedObjectsGC466=== RUN TestOrphanedObjectsGCStressTest467=== PAUSE TestOrphanedObjectsGCStressTest468=== RUN TestResurrectedObjectNotDeleted469=== PAUSE TestResurrectedObjectNotDeleted470=== RUN TestParseSingleRange471=== PAUSE TestParseSingleRange472=== RUN TestIsValidCachePath473=== PAUSE TestIsValidCachePath474=== RUN TestReadProxyNarinfo475=== PAUSE TestReadProxyNarinfo476=== RUN TestReadProxyNarinfoAlreadyDecompressed477=== PAUSE TestReadProxyNarinfoAlreadyDecompressed478=== RUN TestReadProxyNarStreaming479=== PAUSE TestReadProxyNarStreaming480=== RUN TestReadProxy404481=== PAUSE TestReadProxy404482=== RUN TestReadProxyInvalidPath483=== PAUSE TestReadProxyInvalidPath484=== RUN TestReadProxyHead485=== PAUSE TestReadProxyHead486=== RUN TestReadProxyConditionalGet487=== PAUSE TestReadProxyConditionalGet488=== RUN TestReadProxyRootRedirectsToIndexHTML489=== PAUSE TestReadProxyRootRedirectsToIndexHTML490=== RUN TestReadProxyDisabled491=== PAUSE TestReadProxyDisabled492=== RUN TestReadProxyRangeRequest493=== PAUSE TestReadProxyRangeRequest494=== RUN TestRedundantMultipartUpload495=== PAUSE TestRedundantMultipartUpload496=== RUN TestCompleteMultipartUpload_ErrorButObjectExists497=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists498=== RUN TestCompletedNarNotReofferedAcrossClosures499=== PAUSE TestCompletedNarNotReofferedAcrossClosures500=== RUN TestPresignedUploadRegisteredBeforeCommit501=== PAUSE TestPresignedUploadRegisteredBeforeCommit502=== RUN TestService_Rustfstest503=== PAUSE TestService_Rustfstest504=== RUN TestParseSize505=== PAUSE TestParseSize506=== RUN TestSkippedUploadsHandler507=== PAUSE TestSkippedUploadsHandler508=== RUN TestSystemdListenerNotActivated509--- PASS: TestSystemdListenerNotActivated (0.00s)510=== RUN TestWatchdogBeatsWhenHealthy511--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)512=== RUN TestWatchdogSkipsWhenUnhealthy5132026/08/06 11:09:53 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5142026/08/06 11:09:53 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5152026/08/06 11:09:53 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5162026/08/06 11:09:53 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5172026/08/06 11:09:54 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5182026/08/06 11:09:54 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5192026/08/06 11:09:54 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5202026/08/06 11:09:54 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5212026/08/06 11:09:54 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5222026/08/06 11:09:54 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"523--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)524=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle525=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle526=== RUN TestProxyWriteTimeout527=== PAUSE TestProxyWriteTimeout528=== RUN TestIsValidUploadKey529=== PAUSE TestIsValidUploadKey530=== RUN TestUploadHandlersRejectInvalidKeys531=== PAUSE TestUploadHandlersRejectInvalidKeys532=== RUN TestUploadHandlersRejectOversizedBody533=== PAUSE TestUploadHandlersRejectOversizedBody534=== RUN TestService_cleanupPendingClosuresHandler535=== PAUSE TestService_cleanupPendingClosuresHandler536=== RUN TestService_createPendingClosureHandler537=== PAUSE TestService_createPendingClosureHandler538=== RUN TestService_verifyS3Integrity539=== PAUSE TestService_verifyS3Integrity540=== RUN TestCompleteMultipartUnregistered541=== PAUSE TestCompleteMultipartUnregistered542=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT543=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT544=== CONT TestService_AuthMiddleware545=== CONT TestUploadHandlersRejectOversizedBody546=== CONT TestReadProxyDisabled547=== CONT TestService_NativeMTLS548=== CONT TestReadProxyNarinfo549=== CONT TestUploadHandlersRejectInvalidKeys550=== CONT TestIsValidUploadKey551=== RUN TestIsValidUploadKey/narinfo552=== CONT TestProxyWriteTimeout553=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle554=== CONT TestSkippedUploadsHandler555=== CONT TestParseSize556=== CONT TestService_Rustfstest557=== CONT TestPresignedUploadRegisteredBeforeCommit558=== CONT TestCompletedNarNotReofferedAcrossClosures559=== CONT TestCompleteMultipartUpload_ErrorButObjectExists560=== CONT TestRedundantMultipartUpload561=== CONT TestReadProxyRangeRequest562=== CONT TestReadProxyRootRedirectsToIndexHTML563=== CONT TestReadProxyConditionalGet564=== CONT TestReadProxyHead565=== CONT TestReadProxyInvalidPath566=== CONT TestReadProxy404567=== CONT TestReadProxyNarStreaming568=== CONT TestReadProxyNarinfoAlreadyDecompressed569=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info570=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info571=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal572=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal573=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key574=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key575=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key576=== PAUSE TestIsValidUploadKey/narinfo577=== RUN TestIsValidUploadKey/nar_zst578=== RUN TestProxyWriteTimeout/narinfo579--- PASS: TestParseSize (0.00s)580=== CONT TestGCTaskStore_StartNew581--- PASS: TestGCTaskStore_StartNew (0.00s)582=== CONT TestMetricsInventory5832026/08/06 11:09:54 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000584=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key585=== CONT TestNARDeduplicationMetadataUploadBug586=== PAUSE TestIsValidUploadKey/nar_zst587=== RUN TestIsValidUploadKey/nar_xz588=== PAUSE TestIsValidUploadKey/nar_xz589=== RUN TestIsValidUploadKey/nar_plain590=== PAUSE TestIsValidUploadKey/nar_plain591=== RUN TestIsValidUploadKey/listing592=== PAUSE TestIsValidUploadKey/listing593=== RUN TestIsValidUploadKey/build_log594=== PAUSE TestIsValidUploadKey/build_log595=== RUN TestIsValidUploadKey/build_log_home-manager_file596=== PAUSE TestIsValidUploadKey/build_log_home-manager_file597=== RUN TestIsValidUploadKey/build_log_plus_in_name598=== PAUSE TestIsValidUploadKey/build_log_plus_in_name599=== RUN TestIsValidUploadKey/build_log_question_mark600=== PAUSE TestIsValidUploadKey/build_log_question_mark601=== RUN TestIsValidUploadKey/build_log_equals602=== PAUSE TestIsValidUploadKey/build_log_equals603=== RUN TestIsValidUploadKey/realisation604=== PAUSE TestIsValidUploadKey/realisation605=== RUN TestIsValidUploadKey/realisation_plus_in_output606=== PAUSE TestIsValidUploadKey/realisation_plus_in_output607=== RUN TestIsValidUploadKey/nix-cache-info608=== PAUSE TestIsValidUploadKey/nix-cache-info609=== RUN TestIsValidUploadKey/index.html610=== PAUSE TestIsValidUploadKey/index.html611=== RUN TestIsValidUploadKey/narinfo_key,_nar_type612=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type613=== RUN TestIsValidUploadKey/nar_key,_narinfo_type614=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type615=== RUN TestIsValidUploadKey/listing_key,_narinfo_type616=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type617=== RUN TestIsValidUploadKey/traversal618=== PAUSE TestIsValidUploadKey/traversal619=== RUN TestIsValidUploadKey/traversal_nar620=== PAUSE TestProxyWriteTimeout/narinfo621=== RUN TestProxyWriteTimeout/1_GiB_nar622=== PAUSE TestProxyWriteTimeout/1_GiB_nar623=== RUN TestProxyWriteTimeout/10_GiB_nar624=== PAUSE TestProxyWriteTimeout/10_GiB_nar625=== RUN TestProxyWriteTimeout/unknown_size626=== PAUSE TestProxyWriteTimeout/unknown_size627=== PAUSE TestIsValidUploadKey/traversal_nar628=== RUN TestIsValidUploadKey/absolute629=== PAUSE TestIsValidUploadKey/absolute630=== RUN TestIsValidUploadKey/empty_key631=== PAUSE TestIsValidUploadKey/empty_key632=== RUN TestIsValidUploadKey/unknown_type633=== PAUSE TestIsValidUploadKey/unknown_type634=== CONT TestCacheConfigHandlerMaxNarSize635=== CONT TestCreatePendingClosureRejectsOversizedNAR636--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)637=== CONT TestGenerateLandingPage6382026/08/06 11:09:54 INFO Received uploads request method=POST path=/api/pending_closures639--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)640=== CONT TestService_healthCheckHandler641--- PASS: TestSkippedUploadsHandler (0.08s)642=== CONT TestGracefulShutdownDrainsInflight6432026/08/06 11:09:54 INFO Starting HTTP server address=127.0.0.1:445356442026/08/06 11:09:54 INFO Shutdown signal received, draining in-flight requests timeout=10s645--- PASS: TestGenerateLandingPage (0.01s)646=== CONT TestGCTaskStore_Fail647--- PASS: TestGCTaskStore_Fail (0.00s)648=== CONT TestGCTaskStore_PhaseUpdates649--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)650=== CONT TestGCTaskStore_CompletedAllowsNewTask651--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)652=== CONT TestGCTaskStore_GetReturnsLatest653--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)654=== CONT TestGCTaskStore_GetEmpty655--- PASS: TestGCTaskStore_GetEmpty (0.00s)656=== CONT TestGCTaskStore_ConflictDifferentParams657--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)658=== CONT TestGCTaskStore_DeduplicateSameParams659--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)660=== CONT TestService_verifyS3Integrity6612026-08-06 11:09:54.260 UTC [979] ERROR: relation "goose_db_version" does not exist at character 366622026-08-06 11:09:54.260 UTC [979] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6632026-08-06 11:09:54.261 UTC [981] ERROR: relation "goose_db_version" does not exist at character 366642026-08-06 11:09:54.261 UTC [981] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6652026-08-06 11:09:54.261 UTC [980] ERROR: relation "goose_db_version" does not exist at character 366662026-08-06 11:09:54.261 UTC [980] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6672026-08-06 11:09:54.261 UTC [982] ERROR: relation "goose_db_version" does not exist at character 366682026-08-06 11:09:54.261 UTC [982] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC669--- PASS: TestGracefulShutdownDrainsInflight (0.07s)670=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT671=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure672=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure673=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart674=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart675=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts676=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts677=== CONT TestCompleteMultipartUnregistered6782026/08/06 11:09:54 OK 20241026095416_initial_model.sql (102.58ms)6792026/08/06 11:09:54 OK 20241026095416_initial_model.sql (102.16ms)6802026/08/06 11:09:54 OK 20241026095416_initial_model.sql (106.63ms)6812026-08-06 11:09:54.452 UTC [987] ERROR: relation "goose_db_version" does not exist at character 366822026-08-06 11:09:54.452 UTC [987] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6832026/08/06 11:09:54 OK 20241026095416_initial_model.sql (108.42ms)6842026/08/06 11:09:54 OK 20251210153512_drop_unused_gin_index.sql (5.1ms)6852026/08/06 11:09:54 OK 20251210153512_drop_unused_gin_index.sql (4.92ms)6862026-08-06 11:09:54.456 UTC [988] ERROR: relation "goose_db_version" does not exist at character 366872026-08-06 11:09:54.456 UTC [988] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6882026/08/06 11:09:54 OK 20251210153512_drop_unused_gin_index.sql (4.92ms)6892026-08-06 11:09:54.457 UTC [989] ERROR: relation "goose_db_version" does not exist at character 366902026-08-06 11:09:54.457 UTC [989] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6912026/08/06 11:09:54 OK 20251210153512_drop_unused_gin_index.sql (4.56ms)6922026-08-06 11:09:54.459 UTC [990] ERROR: relation "goose_db_version" does not exist at character 366932026-08-06 11:09:54.459 UTC [990] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6942026/08/06 11:09:54 OK 20251218171726_add_pins.sql (7.34ms)6952026/08/06 11:09:54 OK 20251218171726_add_pins.sql (8.07ms)6962026-08-06 11:09:54.465 UTC [991] ERROR: relation "goose_db_version" does not exist at character 366972026-08-06 11:09:54.465 UTC [991] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6982026/08/06 11:09:54 OK 20251218171726_add_pins.sql (8.51ms)6992026/08/06 11:09:54 OK 20251218171726_add_pins.sql (9.65ms)7002026-08-06 11:09:54.466 UTC [992] ERROR: relation "goose_db_version" does not exist at character 367012026-08-06 11:09:54.466 UTC [992] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7022026-08-06 11:09:54.469 UTC [993] ERROR: relation "goose_db_version" does not exist at character 367032026-08-06 11:09:54.469 UTC [993] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7042026-08-06 11:09:54.474 UTC [994] ERROR: relation "goose_db_version" does not exist at character 367052026-08-06 11:09:54.474 UTC [994] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7062026-08-06 11:09:54.480 UTC [995] ERROR: relation "goose_db_version" does not exist at character 367072026-08-06 11:09:54.480 UTC [995] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7082026/08/06 11:09:54 OK 20260628120000_add_object_size_and_stats.sql (19.98ms)7092026/08/06 11:09:54 goose: successfully migrated database to version: 202606281200007102026/08/06 11:09:54 OK 20260628120000_add_object_size_and_stats.sql (21.06ms)7112026/08/06 11:09:54 OK 20260628120000_add_object_size_and_stats.sql (19.34ms)7122026/08/06 11:09:54 goose: successfully migrated database to version: 202606281200007132026/08/06 11:09:54 goose: successfully migrated database to version: 202606281200007142026/08/06 11:09:54 OK 20260628120000_add_object_size_and_stats.sql (19.29ms)7152026/08/06 11:09:54 goose: successfully migrated database to version: 202606281200007162026/08/06 11:09:54 OK 1_commit_pending_closure.sql (6.91ms)7172026/08/06 11:09:54 OK 1_commit_pending_closure.sql (5.66ms)7182026/08/06 11:09:54 OK 1_commit_pending_closure.sql (5.55ms)7192026/08/06 11:09:54 OK 1_commit_pending_closure.sql (5.61ms)7202026/08/06 11:09:54 OK 2_object_stats_trigger.sql (3.03ms)7212026/08/06 11:09:54 goose: up to current file version: 27222026/08/06 11:09:54 OK 20241026095416_initial_model.sql (31.43ms)7232026/08/06 11:09:54 OK 2_object_stats_trigger.sql (2.62ms)7242026/08/06 11:09:54 goose: up to current file version: 27252026/08/06 11:09:54 OK 2_object_stats_trigger.sql (2.69ms)7262026/08/06 11:09:54 goose: up to current file version: 27272026/08/06 11:09:54 OK 2_object_stats_trigger.sql (4.45ms)7282026/08/06 11:09:54 goose: up to current file version: 27292026/08/06 11:09:54 OK 20241026095416_initial_model.sql (27.98ms)7302026-08-06 11:09:54.496 UTC [996] ERROR: relation "goose_db_version" does not exist at character 367312026-08-06 11:09:54.496 UTC [996] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7322026/08/06 11:09:54 OK 20241026095416_initial_model.sql (30.45ms)7332026/08/06 11:09:54 OK 20241026095416_initial_model.sql (27.6ms)7342026/08/06 11:09:54 OK 20251210153512_drop_unused_gin_index.sql (4.19ms)7352026/08/06 11:09:54 OK 20251210153512_drop_unused_gin_index.sql (3.5ms)7362026/08/06 11:09:54 OK 20241026095416_initial_model.sql (15.21ms)7372026/08/06 11:09:54 OK 20251210153512_drop_unused_gin_index.sql (3.65ms)7382026/08/06 11:09:54 OK 20251210153512_drop_unused_gin_index.sql (3.55ms)7392026/08/06 11:09:54 OK 20241026095416_initial_model.sql (16.57ms)7402026/08/06 11:09:54 OK 20251210153512_drop_unused_gin_index.sql (2.54ms)7412026/08/06 11:09:54 OK 20251218171726_add_pins.sql (5.29ms)7422026/08/06 11:09:54 OK 20251218171726_add_pins.sql (7.21ms)7432026/08/06 11:09:54 OK 20251210153512_drop_unused_gin_index.sql (3.7ms)7442026/08/06 11:09:54 OK 20251218171726_add_pins.sql (6.03ms)7452026/08/06 11:09:54 OK 20251218171726_add_pins.sql (6.15ms)7462026/08/06 11:09:54 OK 20251218171726_add_pins.sql (4.93ms)7472026/08/06 11:09:54 OK 20260628120000_add_object_size_and_stats.sql (5.02ms)7482026/08/06 11:09:54 goose: successfully migrated database to version: 202606281200007492026/08/06 11:09:54 OK 20241026095416_initial_model.sql (16.1ms)7502026/08/06 11:09:54 OK 20260628120000_add_object_size_and_stats.sql (6.6ms)7512026/08/06 11:09:54 goose: successfully migrated database to version: 202606281200007522026/08/06 11:09:54 INFO Received uploads request method=POST path=/api/pending_closures7532026/08/06 11:09:54 OK 20260628120000_add_object_size_and_stats.sql (5.67ms)7542026/08/06 11:09:54 goose: successfully migrated database to version: 202606281200007552026/08/06 11:09:54 OK 20251210153512_drop_unused_gin_index.sql (3.08ms)7562026/08/06 11:09:54 OK 20241026095416_initial_model.sql (17.79ms)7572026/08/06 11:09:54 OK 20260628120000_add_object_size_and_stats.sql (5.83ms)7582026/08/06 11:09:54 goose: successfully migrated database to version: 202606281200007592026/08/06 11:09:54 OK 20251218171726_add_pins.sql (6.99ms)7602026/08/06 11:09:54 OK 1_commit_pending_closure.sql (4.53ms)7612026/08/06 11:09:54 OK 20260628120000_add_object_size_and_stats.sql (5.98ms)7622026/08/06 11:09:54 goose: successfully migrated database to version: 202606281200007632026/08/06 11:09:54 OK 1_commit_pending_closure.sql (10.84ms)7642026/08/06 11:09:54 OK 1_commit_pending_closure.sql (9.09ms)765--- PASS: TestService_Rustfstest (0.41s)766=== CONT TestService_createPendingClosureHandler7672026/08/06 11:09:54 OK 1_commit_pending_closure.sql (12.32ms)7682026/08/06 11:09:54 OK 20260628120000_add_object_size_and_stats.sql (12.11ms)7692026/08/06 11:09:54 OK 20251218171726_add_pins.sql (12.29ms)7702026/08/06 11:09:54 OK 20241026095416_initial_model.sql (32.87ms)7712026/08/06 11:09:54 goose: successfully migrated database to version: 202606281200007722026/08/06 11:09:54 OK 20251210153512_drop_unused_gin_index.sql (12.38ms)7732026/08/06 11:09:54 OK 20241026095416_initial_model.sql (18.71ms)7742026/08/06 11:09:54 OK 2_object_stats_trigger.sql (10.88ms)7752026/08/06 11:09:54 goose: up to current file version: 27762026/08/06 11:09:54 OK 1_commit_pending_closure.sql (10.71ms)7772026/08/06 11:09:54 OK 2_object_stats_trigger.sql (4.71ms)7782026/08/06 11:09:54 goose: up to current file version: 27792026/08/06 11:09:54 OK 2_object_stats_trigger.sql (4.78ms)7802026/08/06 11:09:54 goose: up to current file version: 27812026/08/06 11:09:54 OK 2_object_stats_trigger.sql (2.07ms)7822026/08/06 11:09:54 goose: up to current file version: 27832026/08/06 11:09:54 OK 2_object_stats_trigger.sql (2.73ms)7842026/08/06 11:09:54 goose: up to current file version: 27852026/08/06 11:09:54 OK 20251210153512_drop_unused_gin_index.sql (2.73ms)7862026/08/06 11:09:54 OK 20251210153512_drop_unused_gin_index.sql (2.37ms)7872026/08/06 11:09:54 OK 1_commit_pending_closure.sql (2.52ms)7882026/08/06 11:09:54 OK 20251218171726_add_pins.sql (3.04ms)7892026/08/06 11:09:54 OK 20260628120000_add_object_size_and_stats.sql (3.17ms)7902026/08/06 11:09:54 goose: successfully migrated database to version: 202606281200007912026/08/06 11:09:54 OK 20251218171726_add_pins.sql (2.92ms)7922026/08/06 11:09:54 OK 2_object_stats_trigger.sql (2.4ms)7932026/08/06 11:09:54 goose: up to current file version: 27942026/08/06 11:09:54 OK 20260628120000_add_object_size_and_stats.sql (2.78ms)7952026/08/06 11:09:54 goose: successfully migrated database to version: 202606281200007962026/08/06 11:09:54 OK 1_commit_pending_closure.sql (2.66ms)7972026/08/06 11:09:54 OK 20251218171726_add_pins.sql (3.24ms)7982026/08/06 11:09:54 OK 2_object_stats_trigger.sql (1.08ms)7992026/08/06 11:09:54 goose: up to current file version: 2800--- PASS: TestReadProxyDisabled (0.42s)801=== CONT TestService_cleanupPendingClosuresHandler8022026/08/06 11:09:54 OK 1_commit_pending_closure.sql (2.9ms)8032026/08/06 11:09:54 OK 20260628120000_add_object_size_and_stats.sql (3.46ms)8042026/08/06 11:09:54 goose: successfully migrated database to version: 202606281200008052026/08/06 11:09:54 OK 2_object_stats_trigger.sql (950.87µs)8062026/08/06 11:09:54 goose: up to current file version: 28072026/08/06 11:09:54 OK 20260628120000_add_object_size_and_stats.sql (4.58ms)8082026/08/06 11:09:54 goose: successfully migrated database to version: 202606281200008092026-08-06 11:09:54.536 UTC [999] ERROR: relation "goose_db_version" does not exist at character 368102026-08-06 11:09:54.536 UTC [999] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8112026/08/06 11:09:54 OK 1_commit_pending_closure.sql (3ms)812{"timestamp":"2026-08-06T11:09:54.53777381Z","level":"ERROR","duration":"540.088µ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":"/build/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(393)"}813{"timestamp":"2026-08-06T11:09:54.538686087Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"bfe4e85a-caf7-4224-b8a4-26c9850842da","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"PUT","uri":"/bucket13/","status_code":503,"duration_ms":1,"result":"server_error","target":"rustfs::server::layer","filename":"rustfs/src/server/layer.rs","line_number":392,"threadName":"rustfs-worker","threadId":"ThreadId(393)"}8142026/08/06 11:09:54 OK 1_commit_pending_closure.sql (3.48ms)8152026/08/06 11:09:54 OK 2_object_stats_trigger.sql (1.7ms)8162026/08/06 11:09:54 goose: up to current file version: 28172026/08/06 11:09:54 OK 2_object_stats_trigger.sql (1.08ms)8182026/08/06 11:09:54 goose: up to current file version: 28192026-08-06 11:09:54.541 UTC [1001] ERROR: relation "goose_db_version" does not exist at character 368202026-08-06 11:09:54.541 UTC [1001] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8212026-08-06 11:09:54.541 UTC [1004] ERROR: relation "goose_db_version" does not exist at character 368222026-08-06 11:09:54.541 UTC [1004] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8232026-08-06 11:09:54.541 UTC [1003] ERROR: relation "goose_db_version" does not exist at character 368242026-08-06 11:09:54.541 UTC [1003] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC825{"timestamp":"2026-08-06T11:09:54.541786095Z","level":"ERROR","duration":"353.619µ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":"/build/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(585)"}826{"timestamp":"2026-08-06T11:09:54.541837685Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"37d835ae-ba06-42f8-a7be-fb0ee72d1a75","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"PUT","uri":"/bucket14/","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(585)"}8272026-08-06 11:09:54.542 UTC [1006] ERROR: relation "goose_db_version" does not exist at character 368282026-08-06 11:09:54.542 UTC [1006] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8292026-08-06 11:09:54.542 UTC [1005] ERROR: relation "goose_db_version" does not exist at character 368302026-08-06 11:09:54.542 UTC [1005] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8312026-08-06 11:09:54.543 UTC [1007] ERROR: relation "goose_db_version" does not exist at character 368322026-08-06 11:09:54.543 UTC [1007] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8332026-08-06 11:09:54.543 UTC [1008] ERROR: relation "goose_db_version" does not exist at character 368342026-08-06 11:09:54.543 UTC [1008] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8352026-08-06 11:09:54.545 UTC [1010] ERROR: relation "goose_db_version" does not exist at character 368362026-08-06 11:09:54.545 UTC [1010] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8372026-08-06 11:09:54.545 UTC [1009] ERROR: relation "goose_db_version" does not exist at character 368382026-08-06 11:09:54.545 UTC [1009] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC839--- PASS: TestReadProxyInvalidPath (0.36s)840=== CONT TestOrphanedObjectsGCStressTest841--- PASS: TestReadProxyRangeRequest (0.44s)842=== CONT TestIsValidCachePath843=== RUN TestIsValidCachePath/narinfo844=== PAUSE TestIsValidCachePath/narinfo845=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars846=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars847=== RUN TestIsValidCachePath/nar_zst848=== PAUSE TestIsValidCachePath/nar_zst849=== RUN TestIsValidCachePath/nar_xz850=== PAUSE TestIsValidCachePath/nar_xz851=== RUN TestIsValidCachePath/nar_bz2852=== PAUSE TestIsValidCachePath/nar_bz2853=== RUN TestIsValidCachePath/nar_uncompressed854=== PAUSE TestIsValidCachePath/nar_uncompressed855=== RUN TestIsValidCachePath/ls856=== PAUSE TestIsValidCachePath/ls857=== RUN TestIsValidCachePath/log858=== PAUSE TestIsValidCachePath/log859=== RUN TestIsValidCachePath/realisation860=== PAUSE TestIsValidCachePath/realisation861=== RUN TestIsValidCachePath/nix-cache-info862=== PAUSE TestIsValidCachePath/nix-cache-info863=== RUN TestIsValidCachePath/index.html864=== PAUSE TestIsValidCachePath/index.html865=== RUN TestIsValidCachePath/traversal_parent866=== PAUSE TestIsValidCachePath/traversal_parent867=== RUN TestIsValidCachePath/traversal_in_middle868=== PAUSE TestIsValidCachePath/traversal_in_middle869=== RUN TestIsValidCachePath/invalid_char_e870=== PAUSE TestIsValidCachePath/invalid_char_e871=== RUN TestIsValidCachePath/invalid_char_u872=== PAUSE TestIsValidCachePath/invalid_char_u873=== RUN TestIsValidCachePath/random_path874=== PAUSE TestIsValidCachePath/random_path875=== RUN TestIsValidCachePath/empty876=== PAUSE TestIsValidCachePath/empty877=== RUN TestIsValidCachePath/leading_slash878=== PAUSE TestIsValidCachePath/leading_slash879=== RUN TestIsValidCachePath/wrong_extension880=== PAUSE TestIsValidCachePath/wrong_extension881=== RUN TestIsValidCachePath/short_hash882=== PAUSE TestIsValidCachePath/short_hash883=== CONT TestParseSingleRange884=== RUN TestParseSingleRange/none885=== PAUSE TestParseSingleRange/none886=== RUN TestParseSingleRange/unknown_unit887=== PAUSE TestParseSingleRange/unknown_unit888=== RUN TestParseSingleRange/multi-range_ignored889=== PAUSE TestParseSingleRange/multi-range_ignored890=== RUN TestParseSingleRange/malformed_no_dash891=== PAUSE TestParseSingleRange/malformed_no_dash892=== RUN TestParseSingleRange/malformed_both_empty893=== PAUSE TestParseSingleRange/malformed_both_empty894=== RUN TestParseSingleRange/malformed_end_before_start895=== PAUSE TestParseSingleRange/malformed_end_before_start896=== RUN TestParseSingleRange/closed897=== PAUSE TestParseSingleRange/closed898=== RUN TestParseSingleRange/open-ended899=== PAUSE TestParseSingleRange/open-ended900=== RUN TestParseSingleRange/end_clamped_to_size901=== PAUSE TestParseSingleRange/end_clamped_to_size902=== RUN TestParseSingleRange/suffix903=== PAUSE TestParseSingleRange/suffix904=== RUN TestParseSingleRange/suffix_exceeds_size905=== PAUSE TestParseSingleRange/suffix_exceeds_size906=== RUN TestParseSingleRange/single_byte907=== PAUSE TestParseSingleRange/single_byte908=== RUN TestParseSingleRange/start_past_EOF909=== PAUSE TestParseSingleRange/start_past_EOF910=== RUN TestParseSingleRange/start_far_past_EOF911=== PAUSE TestParseSingleRange/start_far_past_EOF912=== CONT TestResurrectedObjectNotDeleted9132026/08/06 11:09:54 OK 20241026095416_initial_model.sql (13.12ms)9142026/08/06 11:09:54 OK 20251210153512_drop_unused_gin_index.sql (2.04ms)9152026/08/06 11:09:54 OK 20241026095416_initial_model.sql (12.26ms)9162026/08/06 11:09:54 OK 20241026095416_initial_model.sql (11.73ms)9172026/08/06 11:09:54 OK 20241026095416_initial_model.sql (12.87ms)9182026/08/06 11:09:54 OK 20251210153512_drop_unused_gin_index.sql (2.51ms)9192026/08/06 11:09:54 INFO Received uploads request method=POST path=/api/pending_closures9202026/08/06 11:09:54 OK 20241026095416_initial_model.sql (12.45ms)9212026/08/06 11:09:54 OK 20241026095416_initial_model.sql (14.09ms)9222026/08/06 11:09:54 OK 20241026095416_initial_model.sql (14.14ms)9232026/08/06 11:09:54 OK 20241026095416_initial_model.sql (14.01ms)9242026/08/06 11:09:54 OK 20241026095416_initial_model.sql (14.49ms)9252026/08/06 11:09:54 OK 20251218171726_add_pins.sql (5.08ms)9262026/08/06 11:09:54 OK 20241026095416_initial_model.sql (12.23ms)9272026/08/06 11:09:54 OK 20251210153512_drop_unused_gin_index.sql (1.88ms)9282026/08/06 11:09:54 OK 20251210153512_drop_unused_gin_index.sql (3.04ms)9292026/08/06 11:09:54 OK 20251210153512_drop_unused_gin_index.sql (1.9ms)9302026/08/06 11:09:54 OK 20251210153512_drop_unused_gin_index.sql (1.9ms)9312026/08/06 11:09:54 OK 20251218171726_add_pins.sql (4.01ms)9322026/08/06 11:09:54 OK 20251210153512_drop_unused_gin_index.sql (2.31ms)9332026/08/06 11:09:54 OK 20251210153512_drop_unused_gin_index.sql (2.62ms)9342026/08/06 11:09:54 OK 20251210153512_drop_unused_gin_index.sql (2.69ms)9352026/08/06 11:09:54 OK 20251210153512_drop_unused_gin_index.sql (2.98ms)9362026/08/06 11:09:54 OK 20251218171726_add_pins.sql (3.05ms)9372026/08/06 11:09:54 OK 20251218171726_add_pins.sql (3.22ms)9382026/08/06 11:09:54 OK 20260628120000_add_object_size_and_stats.sql (4.55ms)9392026/08/06 11:09:54 goose: successfully migrated database to version: 202606281200009402026/08/06 11:09:54 OK 20251218171726_add_pins.sql (3.24ms)9412026/08/06 11:09:54 OK 20251218171726_add_pins.sql (3.82ms)9422026/08/06 11:09:54 OK 20251218171726_add_pins.sql (3.14ms)9432026/08/06 11:09:54 OK 20260628120000_add_object_size_and_stats.sql (3.35ms)9442026/08/06 11:09:54 goose: successfully migrated database to version: 202606281200009452026/08/06 11:09:54 OK 20251218171726_add_pins.sql (3.12ms)9462026/08/06 11:09:54 OK 20251218171726_add_pins.sql (3.22ms)9472026/08/06 11:09:54 OK 20260628120000_add_object_size_and_stats.sql (2.91ms)9482026/08/06 11:09:54 goose: successfully migrated database to version: 202606281200009492026/08/06 11:09:54 OK 20251218171726_add_pins.sql (3.87ms)9502026/08/06 11:09:54 OK 20260628120000_add_object_size_and_stats.sql (3.91ms)9512026/08/06 11:09:54 goose: successfully migrated database to version: 202606281200009522026/08/06 11:09:54 OK 1_commit_pending_closure.sql (4.07ms)9532026/08/06 11:09:54 OK 1_commit_pending_closure.sql (3.68ms)954--- PASS: TestReadProxyNarinfoAlreadyDecompressed (0.38s)9552026/08/06 11:09:54 OK 1_commit_pending_closure.sql (3.18ms)956=== CONT TestObjectStatsTrigger9572026/08/06 11:09:54 OK 20260628120000_add_object_size_and_stats.sql (4.29ms)9582026/08/06 11:09:54 goose: successfully migrated database to version: 202606281200009592026/08/06 11:09:54 OK 20260628120000_add_object_size_and_stats.sql (3.84ms)9602026/08/06 11:09:54 goose: successfully migrated database to version: 202606281200009612026/08/06 11:09:54 OK 20260628120000_add_object_size_and_stats.sql (4.81ms)9622026/08/06 11:09:54 goose: successfully migrated database to version: 202606281200009632026/08/06 11:09:54 OK 2_object_stats_trigger.sql (1.67ms)9642026/08/06 11:09:54 OK 20260628120000_add_object_size_and_stats.sql (4.1ms)9652026/08/06 11:09:54 OK 20260628120000_add_object_size_and_stats.sql (4.68ms)9662026/08/06 11:09:54 goose: successfully migrated database to version: 202606281200009672026/08/06 11:09:54 goose: up to current file version: 29682026/08/06 11:09:54 goose: successfully migrated database to version: 202606281200009692026/08/06 11:09:54 OK 1_commit_pending_closure.sql (2.98ms)9702026/08/06 11:09:54 OK 20260628120000_add_object_size_and_stats.sql (4.63ms)9712026/08/06 11:09:54 goose: successfully migrated database to version: 202606281200009722026/08/06 11:09:54 OK 2_object_stats_trigger.sql (1.61ms)9732026/08/06 11:09:54 goose: up to current file version: 29742026/08/06 11:09:54 OK 2_object_stats_trigger.sql (1.58ms)9752026/08/06 11:09:54 goose: up to current file version: 29762026/08/06 11:09:54 OK 1_commit_pending_closure.sql (2.24ms)9772026/08/06 11:09:54 OK 1_commit_pending_closure.sql (2.2ms)9782026/08/06 11:09:54 OK 1_commit_pending_closure.sql (2.3ms)9792026/08/06 11:09:54 OK 1_commit_pending_closure.sql (2.49ms)9802026/08/06 11:09:54 OK 2_object_stats_trigger.sql (2.28ms)9812026/08/06 11:09:54 goose: up to current file version: 2982{"timestamp":"2026-08-06T11:09:54.578987752Z","level":"ERROR","duration":"288.029µ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":"/build/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(765)"}983{"timestamp":"2026-08-06T11:09:54.579046262Z","level":"ERROR","duration":"226.37µ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":"/build/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(585)"}984{"timestamp":"2026-08-06T11:09:54.579058541Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"1f9fc2ed-9c54-4b4f-b1c7-140f4bf9fdc6","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"PUT","uri":"/bucket16/","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(765)"}985{"timestamp":"2026-08-06T11:09:54.579074241Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"94a6405b-5e02-433a-84aa-f27c8fc7c76a","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"PUT","uri":"/bucket19/","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(585)"}9862026/08/06 11:09:54 OK 1_commit_pending_closure.sql (3.77ms)9872026/08/06 11:09:54 OK 2_object_stats_trigger.sql (2.5ms)9882026/08/06 11:09:54 goose: up to current file version: 29892026/08/06 11:09:54 OK 2_object_stats_trigger.sql (2.58ms)9902026/08/06 11:09:54 goose: up to current file version: 29912026/08/06 11:09:54 OK 1_commit_pending_closure.sql (3.91ms)9922026/08/06 11:09:54 OK 2_object_stats_trigger.sql (2.64ms)9932026/08/06 11:09:54 goose: up to current file version: 2994{"timestamp":"2026-08-06T11:09:54.581207003Z","level":"ERROR","duration":"388.018µ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":"/build/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(586)"}995{"timestamp":"2026-08-06T11:09:54.581273693Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"12fab84f-6ee6-4bf4-b204-1b72e75df59f","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"PUT","uri":"/bucket20/","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(586)"}9962026/08/06 11:09:54 OK 2_object_stats_trigger.sql (3.49ms)9972026/08/06 11:09:54 goose: up to current file version: 29982026/08/06 11:09:54 INFO Received uploads request method=POST path=/api/pending_closures999{"timestamp":"2026-08-06T11:09:54.582581268Z","level":"ERROR","duration":"253.309µ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":"/build/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(765)"}1000{"timestamp":"2026-08-06T11:09:54.582654258Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"6f70e78a-e9ac-44e6-97ec-94a1c4260d23","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"PUT","uri":"/bucket22/","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(765)"}10012026/08/06 11:09:54 OK 2_object_stats_trigger.sql (3.14ms)1002{"timestamp":"2026-08-06T11:09:54.582995686Z","level":"ERROR","duration":"155.799µ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":"/build/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(765)"}10032026/08/06 11:09:54 goose: up to current file version: 21004{"timestamp":"2026-08-06T11:09:54.583013416Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"e1b7bd18-89d5-4a04-8a72-36c30a3ed44f","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"PUT","uri":"/bucket23/","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(765)"}10052026/08/06 11:09:54 OK 2_object_stats_trigger.sql (3.64ms)10062026/08/06 11:09:54 goose: up to current file version: 21007{"timestamp":"2026-08-06T11:09:54.584341451Z","level":"ERROR","duration":"364.628µ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":"/build/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(585)"}1008{"timestamp":"2026-08-06T11:09:54.584409761Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"bd74f050-f420-4379-9312-e8b052041183","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"PUT","uri":"/bucket24/","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(585)"}1009{"timestamp":"2026-08-06T11:09:54.585025519Z","level":"ERROR","duration":"227.71µ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":"/build/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(765)"}1010{"timestamp":"2026-08-06T11:09:54.585077118Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"760af72f-db89-4480-9f9c-e7786a4ce7d8","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"PUT","uri":"/bucket25/","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(765)"}1011{"timestamp":"2026-08-06T11:09:54.590228718Z","level":"ERROR","duration":"67.709µ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":"/build/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(493)"}1012{"timestamp":"2026-08-06T11:09:54.590257338Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"96a89c98-8e7c-40dc-9123-9ef5e1f64bce","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"PUT","uri":"/bucket22/","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(493)"}1013{"timestamp":"2026-08-06T11:09:54.591557463Z","level":"ERROR","duration":"85.019µ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":"/build/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(415)"}1014{"timestamp":"2026-08-06T11:09:54.591584293Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"ec945e49-8237-467a-8cbf-e8978ccd3726","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"PUT","uri":"/bucket23/","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(415)"}10152026/08/06 11:09:54 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10162026/08/06 11:09:54 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=ZDUyOWY2YWYtYjVjMC00NGMxLWJkZGYtYTMzOGUwZmJmNGRlLjMzYWQ0N2ZlLTc2MTAtNDI5Mi05ZmZkLWFhYTQyN2FjNmVhNHgxNzg2MDE0NTk0NTY5MTQzODQw1017--- PASS: TestReadProxyNarStreaming (0.41s)10182026/08/06 11:09:54 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"1019=== CONT TestOrphanedObjectsGC1020--- PASS: TestService_AuthMiddleware (0.49s)1021=== CONT TestMultipartCleanup10222026/08/06 11:09:54 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst10232026/08/06 11:09:54 INFO Received uploads request method=POST path=/api/pending_closures10242026/08/06 11:09:54 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=ZDUyOWY2YWYtYjVjMC00NGMxLWJkZGYtYTMzOGUwZmJmNGRlLjMzYWQ0N2ZlLTc2MTAtNDI5Mi05ZmZkLWFhYTQyN2FjNmVhNHgxNzg2MDE0NTk0NTY5MTQzODQw parts=11025--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (0.50s)1026=== CONT TestServerTLSConfig1027=== RUN TestServerTLSConfig/no_client_CA1028=== PAUSE TestServerTLSConfig/no_client_CA1029=== RUN TestServerTLSConfig/missing_CA_file1030=== PAUSE TestServerTLSConfig/missing_CA_file1031=== RUN TestServerTLSConfig/not_a_PEM_file1032=== PAUSE TestServerTLSConfig/not_a_PEM_file1033--- PASS: TestPresignedUploadRegisteredBeforeCommit (0.50s)1034=== CONT TestClientWithDependencies1035=== CONT TestClientErrorHandling1036=== RUN TestClientErrorHandling/InvalidStorePath1037=== PAUSE TestClientErrorHandling/InvalidStorePath1038=== RUN TestClientErrorHandling/InvalidAuthToken1039=== PAUSE TestClientErrorHandling/InvalidAuthToken1040=== RUN TestClientErrorHandling/ServerNotAvailable1041=== PAUSE TestClientErrorHandling/ServerNotAvailable1042=== CONT TestClientMultipleUploads10432026-08-06 11:09:54.625 UTC [1024] ERROR: relation "goose_db_version" does not exist at character 3610442026-08-06 11:09:54.625 UTC [1024] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10452026-08-06 11:09:54.626 UTC [1025] ERROR: relation "goose_db_version" does not exist at character 3610462026-08-06 11:09:54.626 UTC [1025] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10472026/08/06 11:09:54 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1048--- PASS: TestReadProxyHead (0.52s)1049=== CONT TestClientIntegration1050--- PASS: TestService_healthCheckHandler (0.44s)1051=== CONT TestGCMetrics1052--- PASS: TestMetricsInventory (0.52s)1053=== CONT TestGCBugBareHashReferences1054--- PASS: TestReadProxyNarinfo (0.53s)1055=== CONT TestService_AuthMiddleware_OIDC10562026/08/06 11:09:54 INFO OIDC provider initialized name=test10572026/08/06 11:09:54 OK 20241026095416_initial_model.sql (12.99ms)1058--- PASS: TestReadProxyConditionalGet (0.45s)1059=== CONT TestClientCADerivations10602026/08/06 11:09:54 OK 20241026095416_initial_model.sql (15.83ms)10612026/08/06 11:09:54 OK 20251210153512_drop_unused_gin_index.sql (4.08ms)10622026/08/06 11:09:54 INFO Received uploads request method=POST path=/api/pending_closures10632026-08-06 11:09:54.655 UTC [1036] ERROR: relation "goose_db_version" does not exist at character 3610642026-08-06 11:09:54.655 UTC [1036] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10652026/08/06 11:09:54 OK 20251210153512_drop_unused_gin_index.sql (8.05ms)10662026/08/06 11:09:54 OK 20251218171726_add_pins.sql (10.28ms)10672026/08/06 11:09:54 OK 20251218171726_add_pins.sql (3.59ms)10682026/08/06 11:09:54 INFO Received uploads request method=POST path=/api/pending_closures10692026/08/06 11:09:54 OK 20260628120000_add_object_size_and_stats.sql (6.24ms)10702026/08/06 11:09:54 goose: successfully migrated database to version: 2026062812000010712026/08/06 11:09:54 INFO Received uploads request method=POST path=/api/pending_closures10722026/08/06 11:09:54 OK 20260628120000_add_object_size_and_stats.sql (7.51ms)10732026/08/06 11:09:54 goose: successfully migrated database to version: 2026062812000010742026/08/06 11:09:54 OK 1_commit_pending_closure.sql (4.3ms)10752026/08/06 11:09:54 OK 1_commit_pending_closure.sql (4.04ms)10762026-08-06 11:09:54.672 UTC [1040] ERROR: relation "goose_db_version" does not exist at character 3610772026-08-06 11:09:54.672 UTC [1040] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10782026/08/06 11:09:54 OK 20241026095416_initial_model.sql (11.38ms)1079--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.40s)1080=== CONT TestCacheStatsHandler10812026/08/06 11:09:54 OK 2_object_stats_trigger.sql (3.09ms)10822026/08/06 11:09:54 goose: up to current file version: 210832026/08/06 11:09:54 OK 2_object_stats_trigger.sql (3.23ms)10842026/08/06 11:09:54 goose: up to current file version: 210852026/08/06 11:09:54 OK 20251210153512_drop_unused_gin_index.sql (3.42ms)10862026-08-06 11:09:54.677 UTC [1041] ERROR: relation "goose_db_version" does not exist at character 3610872026-08-06 11:09:54.677 UTC [1041] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10882026/08/06 11:09:54 OK 20251218171726_add_pins.sql (4.61ms)10892026/08/06 11:09:54 INFO Received uploads request method=POST path=/api/pending_closures10902026/08/06 11:09:54 INFO Received uploads request method=POST path=/api/pending_closures10912026/08/06 11:09:54 INFO Received uploads request method=POST path=/api/pending_closures10922026/08/06 11:09:54 OK 20260628120000_add_object_size_and_stats.sql (11.7ms)10932026/08/06 11:09:54 goose: successfully migrated database to version: 2026062812000010942026/08/06 11:09:54 INFO Received cleanup request method=DELETE path=/api/pending_closures10952026/08/06 11:09:54 INFO Aborted multipart uploads count=010962026/08/06 11:09:54 OK 20241026095416_initial_model.sql (17.07ms)10972026/08/06 11:09:54 INFO Received uploads request method=POST path=/api/pending_closures10982026/08/06 11:09:54 OK 20241026095416_initial_model.sql (14.47ms)10992026/08/06 11:09:54 OK 20251210153512_drop_unused_gin_index.sql (2.23ms)11002026/08/06 11:09:54 OK 1_commit_pending_closure.sql (7.56ms)11012026/08/06 11:09:54 OK 20251210153512_drop_unused_gin_index.sql (2.97ms)11022026-08-06 11:09:54.704 UTC [1044] ERROR: relation "goose_db_version" does not exist at character 3611032026-08-06 11:09:54.704 UTC [1044] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11042026/08/06 11:09:54 OK 20251218171726_add_pins.sql (4.29ms)11052026/08/06 11:09:54 OK 2_object_stats_trigger.sql (2.85ms)11062026/08/06 11:09:54 goose: up to current file version: 211072026/08/06 11:09:54 OK 20251218171726_add_pins.sql (4.02ms)11082026/08/06 11:09:54 WARN mTLS auth: subject not in bound subjects subject="CN=reader"11092026/08/06 11:09:54 WARN mTLS auth: subject not in bound subjects subject="CN=writer"1110--- PASS: TestService_NativeMTLS (0.59s)1111=== CONT TestCacheConfigHandler1112=== RUN TestCacheConfigHandler/full_config,_no_issuer11132026-08-06 11:09:54.707 UTC [1045] ERROR: relation "goose_db_version" does not exist at character 3611142026-08-06 11:09:54.707 UTC [1045] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1115=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1116=== RUN TestCacheConfigHandler/no_cache_url_configured1117=== PAUSE TestCacheConfigHandler/no_cache_url_configured1118=== RUN TestCacheConfigHandler/no_signing_keys1119=== PAUSE TestCacheConfigHandler/no_signing_keys1120=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1121=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1122=== CONT TestService_AuthMiddleware_MTLSBoundSubjects11232026/08/06 11:09:54 INFO Received cleanup request method=DELETE path=/api/pending_closures11242026/08/06 11:09:54 OK 20260628120000_add_object_size_and_stats.sql (5.12ms)11252026/08/06 11:09:54 goose: successfully migrated database to version: 2026062812000011262026/08/06 11:09:54 INFO Aborted multipart uploads count=111272026/08/06 11:09:54 OK 20260628120000_add_object_size_and_stats.sql (5.47ms)11282026/08/06 11:09:54 goose: successfully migrated database to version: 2026062812000011292026/08/06 11:09:54 OK 1_commit_pending_closure.sql (2.5ms)11302026/08/06 11:09:54 OK 1_commit_pending_closure.sql (4.03ms)11312026/08/06 11:09:54 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete11322026/08/06 11:09:54 INFO Received uploads request method=POST path=/api/pending_closures11332026-08-06 11:09:54.714 UTC [1025] ERROR: Closure does not exist: id=111342026-08-06 11:09:54.714 UTC [1025] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 16 at RAISE11352026-08-06 11:09:54.714 UTC [1025] STATEMENT: -- name: CommitPendingClosure :exec1136 SELECT commit_pending_closure($1::bigint)1137 1138--- PASS: TestService_cleanupPendingClosuresHandler (0.18s)1139=== CONT TestService_ReadAuthMiddleware11402026-08-06 11:09:54.715 UTC [1047] ERROR: relation "goose_db_version" does not exist at character 3611412026-08-06 11:09:54.715 UTC [1047] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11422026/08/06 11:09:54 OK 2_object_stats_trigger.sql (2.44ms)11432026/08/06 11:09:54 goose: up to current file version: 211442026/08/06 11:09:54 OK 2_object_stats_trigger.sql (2.57ms)11452026/08/06 11:09:54 goose: up to current file version: 211462026/08/06 11:09:54 INFO Created nix-cache-info in bucket bucket=bucket1711472026-08-06 11:09:54.725 UTC [1050] ERROR: relation "goose_db_version" does not exist at character 3611482026-08-06 11:09:54.725 UTC [1050] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11492026/08/06 11:09:54 OK 20241026095416_initial_model.sql (12.57ms)1150--- PASS: TestReadProxyRootRedirectsToIndexHTML (0.54s)1151=== CONT TestService_AuthMiddleware_MTLSProxyHeader11522026/08/06 11:09:54 OK 20251210153512_drop_unused_gin_index.sql (9.87ms)11532026/08/06 11:09:54 OK 20241026095416_initial_model.sql (16.85ms)11542026/08/06 11:09:54 OK 20241026095416_initial_model.sql (22.66ms)1155--- PASS: TestReadProxy404 (0.55s)1156=== CONT TestPinProtectsFromGC11572026/08/06 11:09:54 OK 20251210153512_drop_unused_gin_index.sql (2.52ms)11582026/08/06 11:09:54 OK 20251210153512_drop_unused_gin_index.sql (3.75ms)11592026/08/06 11:09:54 OK 20251218171726_add_pins.sql (8.24ms)11602026/08/06 11:09:54 OK 20251218171726_add_pins.sql (5.02ms)11612026/08/06 11:09:54 OK 20251218171726_add_pins.sql (5.77ms)11622026-08-06 11:09:54.749 UTC [1056] ERROR: relation "goose_db_version" does not exist at character 3611632026-08-06 11:09:54.749 UTC [1056] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11642026/08/06 11:09:54 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11652026/08/06 11:09:54 OK 20260628120000_add_object_size_and_stats.sql (6.81ms)11662026/08/06 11:09:54 goose: successfully migrated database to version: 2026062812000011672026/08/06 11:09:54 OK 20260628120000_add_object_size_and_stats.sql (5.33ms)11682026/08/06 11:09:54 goose: successfully migrated database to version: 2026062812000011692026/08/06 11:09:54 OK 20241026095416_initial_model.sql (13.09ms)11702026/08/06 11:09:54 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst1171--- PASS: TestCompleteMultipartUnregistered (0.41s)1172=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info11732026/08/06 11:09:54 INFO Received uploads request method=POST path=/1174=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key11752026/08/06 11:09:54 INFO Received request for more parts method=POST path=/1176=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key11772026/08/06 11:09:54 INFO Received complete multipart upload request method=POST path=/1178=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal11792026/08/06 11:09:54 INFO Received uploads request method=POST path=/1180--- PASS: TestUploadHandlersRejectInvalidKeys (0.08s)1181 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1182 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1183 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1184 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1185=== CONT TestProxyWriteTimeout/narinfo1186=== CONT TestIsValidUploadKey/narinfo1187=== CONT TestProxyWriteTimeout/10_GiB_nar1188=== CONT TestProxyWriteTimeout/1_GiB_nar1189=== CONT TestIsValidUploadKey/realisation_plus_in_output1190=== CONT TestIsValidUploadKey/unknown_type1191=== CONT TestIsValidUploadKey/empty_key1192=== CONT TestIsValidUploadKey/absolute1193=== CONT TestIsValidUploadKey/traversal_nar11942026/08/06 11:09:54 OK 1_commit_pending_closure.sql (3.28ms)1195=== CONT TestIsValidUploadKey/traversal11962026/08/06 11:09:54 OK 20260628120000_add_object_size_and_stats.sql (5.62ms)11972026/08/06 11:09:54 goose: successfully migrated database to version: 202606281200001198=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1199=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1200=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1201=== CONT TestIsValidUploadKey/index.html1202=== CONT TestIsValidUploadKey/nix-cache-info1203=== CONT TestIsValidUploadKey/build_log_home-manager_file1204=== CONT TestIsValidUploadKey/realisation1205=== CONT TestIsValidUploadKey/build_log_equals1206=== CONT TestIsValidUploadKey/build_log_question_mark1207=== CONT TestIsValidUploadKey/build_log_plus_in_name1208=== CONT TestProxyWriteTimeout/unknown_size1209--- PASS: TestProxyWriteTimeout (0.08s)1210 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1211 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1212 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1213 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1214=== CONT TestIsValidUploadKey/nar_plain1215=== CONT TestIsValidUploadKey/listing1216=== CONT TestIsValidUploadKey/nar_xz1217=== CONT TestIsValidUploadKey/nar_zst1218=== CONT TestIsValidUploadKey/build_log1219--- PASS: TestIsValidUploadKey (0.08s)1220 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1221 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1222 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1223 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1224 --- PASS: TestIsValidUploadKey/absolute (0.00s)1225 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1226 --- PASS: TestIsValidUploadKey/traversal (0.00s)1227 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1228 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1229 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1230 --- PASS: TestIsValidUploadKey/index.html (0.00s)1231 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1232 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1233 --- PASS: TestIsValidUploadKey/realisation (0.00s)1234 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1235 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1236 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1237 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1238 --- PASS: TestIsValidUploadKey/listing (0.00s)1239 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1240 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1241 --- PASS: TestIsValidUploadKey/build_log (0.00s)1242=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure12432026/08/06 11:09:54 INFO Received uploads request method=POST path=/12442026/08/06 11:09:54 OK 1_commit_pending_closure.sql (3.23ms)12452026/08/06 11:09:54 OK 20251210153512_drop_unused_gin_index.sql (2.52ms)12462026/08/06 11:09:54 OK 2_object_stats_trigger.sql (2.02ms)12472026/08/06 11:09:54 goose: up to current file version: 212482026/08/06 11:09:54 OK 2_object_stats_trigger.sql (2.07ms)12492026/08/06 11:09:54 goose: up to current file version: 212502026/08/06 11:09:54 OK 1_commit_pending_closure.sql (3.06ms)12512026-08-06 11:09:54.759 UTC [1074] ERROR: relation "goose_db_version" does not exist at character 3612522026-08-06 11:09:54.759 UTC [1074] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12532026/08/06 11:09:54 OK 20251218171726_add_pins.sql (3.96ms)12542026/08/06 11:09:54 OK 2_object_stats_trigger.sql (3.01ms)12552026/08/06 11:09:54 goose: up to current file version: 212562026-08-06 11:09:54.762 UTC [1075] ERROR: relation "goose_db_version" does not exist at character 3612572026-08-06 11:09:54.762 UTC [1075] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12582026-08-06 11:09:54.762 UTC [1076] ERROR: relation "goose_db_version" does not exist at character 3612592026-08-06 11:09:54.762 UTC [1076] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1260=== NAME TestNARDeduplicationMetadataUploadBug1261 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug2814272601/001/store/wfasdbx13kfgl0mb0qisqsjwj9h6khg5-file1.txt12622026/08/06 11:09:54 OK 20260628120000_add_object_size_and_stats.sql (4.82ms)12632026/08/06 11:09:54 goose: successfully migrated database to version: 2026062812000012642026/08/06 11:09:54 OK 1_commit_pending_closure.sql (3.46ms)12652026/08/06 11:09:54 OK 20241026095416_initial_model.sql (10.56ms)12662026/08/06 11:09:54 OK 2_object_stats_trigger.sql (2.75ms)12672026/08/06 11:09:54 goose: up to current file version: 212682026/08/06 11:09:54 INFO Received uploads request method=POST path=/api/pending_closures12692026/08/06 11:09:54 OK 20251210153512_drop_unused_gin_index.sql (2.89ms)12702026-08-06 11:09:54.772 UTC [1078] ERROR: relation "goose_db_version" does not exist at character 3612712026-08-06 11:09:54.772 UTC [1078] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12722026/08/06 11:09:54 OK 20251218171726_add_pins.sql (5.16ms)12732026/08/06 11:09:54 OK 20241026095416_initial_model.sql (10.57ms)12742026/08/06 11:09:54 OK 20241026095416_initial_model.sql (11.48ms)12752026-08-06 11:09:54.780 UTC [1079] ERROR: relation "goose_db_version" does not exist at character 3612762026-08-06 11:09:54.780 UTC [1079] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12772026/08/06 11:09:54 INFO Created nix-cache-info in bucket bucket=bucket3212782026/08/06 11:09:54 OK 20241026095416_initial_model.sql (17.28ms)12792026/08/06 11:09:54 OK 20260628120000_add_object_size_and_stats.sql (12.59ms)12802026/08/06 11:09:54 goose: successfully migrated database to version: 2026062812000012812026/08/06 11:09:54 OK 20251210153512_drop_unused_gin_index.sql (10.65ms)12822026/08/06 11:09:54 OK 20251210153512_drop_unused_gin_index.sql (10.62ms)12832026/08/06 11:09:54 OK 20241026095416_initial_model.sql (11.52ms)12842026/08/06 11:09:54 OK 20251210153512_drop_unused_gin_index.sql (4.89ms)12852026/08/06 11:09:54 OK 1_commit_pending_closure.sql (2.61ms)12862026/08/06 11:09:54 OK 20251218171726_add_pins.sql (3.64ms)12872026/08/06 11:09:54 OK 20251210153512_drop_unused_gin_index.sql (2.33ms)12882026/08/06 11:09:54 OK 2_object_stats_trigger.sql (2.1ms)12892026/08/06 11:09:54 goose: up to current file version: 212902026/08/06 11:09:54 OK 20251218171726_add_pins.sql (4.57ms)12912026/08/06 11:09:54 OK 20251218171726_add_pins.sql (5.46ms)12922026/08/06 11:09:54 OK 20251218171726_add_pins.sql (4.16ms)12932026/08/06 11:09:54 OK 20260628120000_add_object_size_and_stats.sql (4.28ms)12942026/08/06 11:09:54 goose: successfully migrated database to version: 2026062812000012952026/08/06 11:09:54 OK 20241026095416_initial_model.sql (10ms)12962026/08/06 11:09:54 OK 20260628120000_add_object_size_and_stats.sql (4.11ms)12972026/08/06 11:09:54 goose: successfully migrated database to version: 2026062812000012982026/08/06 11:09:54 OK 20260628120000_add_object_size_and_stats.sql (4.91ms)12992026/08/06 11:09:54 goose: successfully migrated database to version: 2026062812000013002026/08/06 11:09:54 OK 1_commit_pending_closure.sql (3.99ms)13012026/08/06 11:09:54 OK 20260628120000_add_object_size_and_stats.sql (7.32ms)13022026/08/06 11:09:54 goose: successfully migrated database to version: 2026062812000013032026/08/06 11:09:54 OK 20251210153512_drop_unused_gin_index.sql (2.92ms)13042026/08/06 11:09:54 OK 2_object_stats_trigger.sql (1.82ms)13052026/08/06 11:09:54 goose: up to current file version: 213062026/08/06 11:09:54 OK 1_commit_pending_closure.sql (3.1ms)13072026/08/06 11:09:54 OK 1_commit_pending_closure.sql (2.74ms)13082026/08/06 11:09:54 OK 1_commit_pending_closure.sql (2.97ms)13092026/08/06 11:09:54 OK 20251218171726_add_pins.sql (2.6ms)13102026-08-06 11:09:54.806 UTC [1103] ERROR: relation "goose_db_version" does not exist at character 3613112026-08-06 11:09:54.806 UTC [1103] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13122026/08/06 11:09:54 OK 2_object_stats_trigger.sql (1.91ms)13132026/08/06 11:09:54 goose: up to current file version: 213142026/08/06 11:09:54 OK 2_object_stats_trigger.sql (1.86ms)13152026/08/06 11:09:54 goose: up to current file version: 213162026/08/06 11:09:54 OK 2_object_stats_trigger.sql (2ms)13172026/08/06 11:09:54 goose: up to current file version: 213182026/08/06 11:09:54 OK 20260628120000_add_object_size_and_stats.sql (3.24ms)13192026/08/06 11:09:54 goose: successfully migrated database to version: 2026062812000013202026/08/06 11:09:54 INFO Created nix-cache-info in bucket bucket=bucket3413212026/08/06 11:09:54 OK 1_commit_pending_closure.sql (2.05ms)13222026/08/06 11:09:54 OK 2_object_stats_trigger.sql (1.52ms)13232026/08/06 11:09:54 goose: up to current file version: 213242026-08-06 11:09:54.817 UTC [1120] ERROR: relation "goose_db_version" does not exist at character 3613252026-08-06 11:09:54.817 UTC [1120] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1326--- PASS: TestObjectStatsTrigger (0.24s)1327=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart13282026/08/06 11:09:54 INFO Received complete multipart upload request method=POST path=/13292026/08/06 11:09:54 OK 20241026095416_initial_model.sql (8.09ms)13302026/08/06 11:09:54 INFO Created nix-cache-info in bucket bucket=bucket3513312026-08-06 11:09:54.821 UTC [1122] ERROR: relation "goose_db_version" does not exist at character 3613322026-08-06 11:09:54.821 UTC [1122] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13332026/08/06 11:09:54 OK 20251210153512_drop_unused_gin_index.sql (1.62ms)13342026/08/06 11:09:54 OK 20251218171726_add_pins.sql (3.49ms)13352026/08/06 11:09:54 OK 20260628120000_add_object_size_and_stats.sql (4.53ms)13362026/08/06 11:09:54 goose: successfully migrated database to version: 2026062812000013372026/08/06 11:09:54 OK 20241026095416_initial_model.sql (8.54ms)13382026/08/06 11:09:54 OK 20251210153512_drop_unused_gin_index.sql (1.72ms)13392026/08/06 11:09:54 OK 1_commit_pending_closure.sql (2ms)13402026-08-06 11:09:54.834 UTC [1126] ERROR: relation "goose_db_version" does not exist at character 3613412026-08-06 11:09:54.834 UTC [1126] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13422026/08/06 11:09:54 OK 2_object_stats_trigger.sql (1.43ms)13432026/08/06 11:09:54 goose: up to current file version: 21344--- PASS: TestResurrectedObjectNotDeleted (0.28s)1345=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts13462026/08/06 11:09:54 INFO Received request for more parts method=POST path=/13472026/08/06 11:09:54 OK 20241026095416_initial_model.sql (7.84ms)13482026/08/06 11:09:54 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"1349--- PASS: TestCacheStatsHandler (0.16s)1350=== CONT TestIsValidCachePath/narinfo1351=== CONT TestIsValidCachePath/index.html1352=== CONT TestIsValidCachePath/short_hash1353=== CONT TestIsValidCachePath/wrong_extension1354=== CONT TestIsValidCachePath/leading_slash1355=== CONT TestIsValidCachePath/empty1356=== CONT TestIsValidCachePath/random_path1357=== CONT TestIsValidCachePath/invalid_char_u1358=== CONT TestIsValidCachePath/invalid_char_e1359=== CONT TestIsValidCachePath/traversal_in_middle1360=== CONT TestIsValidCachePath/nar_uncompressed1361=== CONT TestIsValidCachePath/traversal_parent1362=== CONT TestIsValidCachePath/nix-cache-info13632026/08/06 11:09:54 INFO Created nix-cache-info in bucket bucket=bucket381364=== CONT TestIsValidCachePath/log1365=== CONT TestIsValidCachePath/ls1366=== CONT TestIsValidCachePath/realisation1367=== CONT TestIsValidCachePath/nar_xz1368=== CONT TestIsValidCachePath/nar_zst1369=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1370=== CONT TestIsValidCachePath/nar_bz21371--- PASS: TestIsValidCachePath (0.00s)1372 --- PASS: TestIsValidCachePath/narinfo (0.00s)1373 --- PASS: TestIsValidCachePath/index.html (0.00s)1374 --- PASS: TestIsValidCachePath/short_hash (0.00s)1375 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1376 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1377 --- PASS: TestIsValidCachePath/empty (0.00s)1378 --- PASS: TestIsValidCachePath/random_path (0.00s)1379 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1380 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1381 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1382 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1383 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1384 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1385 --- PASS: TestIsValidCachePath/log (0.00s)1386 --- PASS: TestIsValidCachePath/ls (0.00s)1387 --- PASS: TestIsValidCachePath/realisation (0.00s)1388 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1389 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1390 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1391 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1392=== CONT TestParseSingleRange/none1393=== CONT TestParseSingleRange/open-ended1394=== CONT TestParseSingleRange/start_far_past_EOF1395=== CONT TestParseSingleRange/start_past_EOF1396=== CONT TestParseSingleRange/single_byte13972026/08/06 11:09:54 OK 20251218171726_add_pins.sql (3.42ms)1398=== CONT TestParseSingleRange/suffix_exceeds_size1399=== CONT TestParseSingleRange/end_clamped_to_size1400=== CONT TestParseSingleRange/malformed_both_empty1401=== CONT TestParseSingleRange/suffix1402=== CONT TestParseSingleRange/closed1403=== CONT TestParseSingleRange/malformed_end_before_start1404=== CONT TestParseSingleRange/multi-range_ignored1405=== CONT TestParseSingleRange/malformed_no_dash1406=== CONT TestParseSingleRange/unknown_unit1407--- PASS: TestParseSingleRange (0.00s)1408 --- PASS: TestParseSingleRange/none (0.00s)1409 --- PASS: TestParseSingleRange/open-ended (0.00s)1410 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1411 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1412 --- PASS: TestParseSingleRange/single_byte (0.00s)1413 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1414 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1415 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1416 --- PASS: TestParseSingleRange/suffix (0.00s)1417 --- PASS: TestParseSingleRange/closed (0.00s)1418 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1419 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1420 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1421 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1422=== CONT TestServerTLSConfig/no_client_CA1423=== CONT TestServerTLSConfig/not_a_PEM_file14242026/08/06 11:09:54 OK 20251210153512_drop_unused_gin_index.sql (1.55ms)1425=== CONT TestServerTLSConfig/missing_CA_file1426--- PASS: TestServerTLSConfig (0.00s)1427 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1428 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)1429 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1430=== CONT TestClientErrorHandling/InvalidStorePath14312026/08/06 11:09:54 OK 20260628120000_add_object_size_and_stats.sql (2.54ms)14322026/08/06 11:09:54 goose: successfully migrated database to version: 2026062812000014332026/08/06 11:09:54 OK 20251218171726_add_pins.sql (2.42ms)14342026/08/06 11:09:54 OK 1_commit_pending_closure.sql (1.74ms)14352026/08/06 11:09:54 OK 20260628120000_add_object_size_and_stats.sql (2.3ms)14362026/08/06 11:09:54 goose: successfully migrated database to version: 2026062812000014372026/08/06 11:09:54 OK 2_object_stats_trigger.sql (837.84µs)14382026/08/06 11:09:54 goose: up to current file version: 214392026/08/06 11:09:54 OK 1_commit_pending_closure.sql (2.39ms)14402026/08/06 11:09:54 OK 2_object_stats_trigger.sql (752.21µs)14412026/08/06 11:09:54 goose: up to current file version: 214422026/08/06 11:09:54 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"14432026/08/06 11:09:54 WARN mTLS auth: bound subjects configured but subject DN unavailable14442026/08/06 11:09:54 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1445--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (0.14s)1446=== CONT TestClientErrorHandling/ServerNotAvailable1447=== NAME TestClientMultipleUploads1448 client_integration_test.go:338: Created store path 0: /build/TestClientMultipleUploads1475070647/001/store/w6g8qv2860n2jzjh6f4yxaxx7gg5m4ig-test-file-0.txt14492026/08/06 11:09:54 OK 20241026095416_initial_model.sql (8.18ms)14502026/08/06 11:09:54 OK 20251210153512_drop_unused_gin_index.sql (1.15ms)14512026/08/06 11:09:54 OK 20251218171726_add_pins.sql (2.59ms)14522026/08/06 11:09:54 WARN mTLS auth: subject not in bound subjects subject="CN=writer"1453--- PASS: TestService_ReadAuthMiddleware (0.14s)1454=== CONT TestClientErrorHandling/InvalidAuthToken14552026/08/06 11:09:54 OK 20260628120000_add_object_size_and_stats.sql (3.06ms)14562026/08/06 11:09:54 goose: successfully migrated database to version: 2026062812000014572026/08/06 11:09:54 OK 1_commit_pending_closure.sql (1.72ms)14582026/08/06 11:09:54 OK 2_object_stats_trigger.sql (1.08ms)14592026/08/06 11:09:54 goose: up to current file version: 21460=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1461=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1462=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1463=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1464=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1465=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1466=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1467=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1468=== CONT TestCacheConfigHandler/full_config,_no_issuer1469=== CONT TestCacheConfigHandler/no_signing_keys1470=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1471=== CONT TestCacheConfigHandler/no_cache_url_configured1472--- PASS: TestCacheConfigHandler (0.00s)1473 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)1474 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)1475 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)1476 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)1477=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token14782026/08/06 11:09:54 INFO OIDC auth successful provider=test1479=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected14802026/08/06 11:09:54 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]1481=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1482=== NAME TestClientWithDependencies1483 client_integration_test.go:593: Built derivation: /build/TestClientWithDependencies575609811/001/store/bgcjg8x79sh0nkb1c9b7b4s331dvr56x-test-script1484=== NAME TestClientIntegration1485 client_integration_test.go:276: Created store path: /build/TestClientIntegration24793408/002/store/4lbdfg87anapnzi7xznh9dr1vp8lzjnd-test-file.txt14862026/08/06 11:09:54 WARN Authentication failed token_preview=eyJhbGciOi...O6urnxbTVg 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]1487=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1488--- PASS: TestService_AuthMiddleware_OIDC (0.22s)1489 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)1490 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)1491 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)1492 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)1493--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.13s)14942026/08/06 11:09:54 INFO Received uploads request method=POST path=/api/pending_closures14952026/08/06 11:09:54 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)14962026/08/06 11:09:54 INFO Uploading wfasdbx13kfgl0mb0qisqsjwj9h6khg5-file1.txt (160B)1497=== NAME TestClientMultipleUploads1498 client_integration_test.go:338: Created store path 1: /build/TestClientMultipleUploads1475070647/001/store/m0an6afz7y6wkhl00mlr6pi5cs4w3qa3-test-file-1.txt14992026/08/06 11:09:54 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"15002026/08/06 11:09:54 INFO Created nix-cache-info in bucket bucket=bucket4415012026/08/06 11:09:54 WARN Failed to register uploaded object key=wfasdbx13kfgl0mb0qisqsjwj9h6khg5.ls error="server returned 404: 404 page not found\n"15022026/08/06 11:09:54 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign15032026/08/06 11:09:54 INFO Signed narinfos id=1 count=115042026/08/06 11:09:54 INFO Uploading 1 narinfos15052026/08/06 11:09:54 INFO Received cleanup request method=DELETE path=/api/pending_closures15062026/08/06 11:09:54 WARN Failed to register uploaded object key=wfasdbx13kfgl0mb0qisqsjwj9h6khg5.narinfo error="server returned 404: 404 page not found\n"15072026/08/06 11:09:54 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete15082026/08/06 11:09:54 INFO Aborted multipart uploads count=11509=== NAME TestClientWithDependencies1510 client_integration_test.go:595: Found 1 dependencies (including self)15112026/08/06 11:09:54 INFO Aborted multipart uploads count=015122026/08/06 11:09:54 INFO Completed upload id=115132026/08/06 11:09:54 INFO Upload complete. (99ms)1514--- PASS: TestMultipartCleanup (0.30s)1515=== NAME TestNARDeduplicationMetadataUploadBug1516 metadata_upload_test.go:54: Retrieved narinfo from S3:1517 StorePath: /build/TestNARDeduplicationMetadataUploadBug2814272601/001/store/wfasdbx13kfgl0mb0qisqsjwj9h6khg5-file1.txt1518 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1519 Compression: zstd1520 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf15212026/08/06 11:09:54 WARN Force mode enabled - objects will be deleted immediately without grace period1522 NarSize: 1601523 References: 1524 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1525 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1526 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1527 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}15282026/08/06 11:09:54 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=015292026/08/06 11:09:54 INFO Vacuumed table table=pending_closures15302026/08/06 11:09:54 INFO Vacuumed table table=pending_objects15312026/08/06 11:09:54 INFO Vacuumed table table=multipart_uploads15322026/08/06 11:09:54 INFO Vacuumed table table=closures15332026/08/06 11:09:54 INFO Vacuumed table table=objects1534=== NAME TestClientMultipleUploads1535 client_integration_test.go:338: Created store path 2: /build/TestClientMultipleUploads1475070647/001/store/gx9pp3v93qh0vg31yb7s9rkm0wfagylh-test-file-2.txt1536--- PASS: TestGCMetrics (0.28s)1537=== NAME TestClientCADerivations1538 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations112306268/001/store/fjpf2cdlzh9n9r1n3kh3a7rdqicz5qgj-ca-test15392026/08/06 11:09:54 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"1540=== NAME TestNARDeduplicationMetadataUploadBug1541 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug2814272601/001/store/d37i3h05q3sa21l91hi1n93gx1xgzxdh-file2.txt15422026-08-06 11:09:54.939 UTC [1431] ERROR: relation "goose_db_version" does not exist at character 3615432026-08-06 11:09:54.939 UTC [1431] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15442026-08-06 11:09:54.939 UTC [1446] ERROR: relation "goose_db_version" does not exist at character 3615452026-08-06 11:09:54.939 UTC [1446] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15462026/08/06 11:09:54 INFO Received uploads request method=POST path=/api/pending_closures1547=== NAME TestPinProtectsFromGC1548 client_integration_test.go:646: Pinned store path: /build/TestPinProtectsFromGC673262370/001/store/97xgimpn6bch4bw49vdnx56h7q3zcvv6-pinned-file.txt1549 client_integration_test.go:647: Unpinned store path: /build/TestPinProtectsFromGC673262370/001/store/lv51rrh94mx4328fsks8lsqdpz2kkflc-unpinned-file.txt15502026/08/06 11:09:54 OK 20241026095416_initial_model.sql (7.13ms)15512026/08/06 11:09:54 OK 20241026095416_initial_model.sql (7.91ms)15522026/08/06 11:09:54 OK 20251210153512_drop_unused_gin_index.sql (852.4µs)15532026/08/06 11:09:54 OK 20251210153512_drop_unused_gin_index.sql (1.14ms)15542026/08/06 11:09:54 OK 20251218171726_add_pins.sql (1.99ms)15552026/08/06 11:09:54 OK 20251218171726_add_pins.sql (3.49ms)15562026/08/06 11:09:54 OK 20260628120000_add_object_size_and_stats.sql (2.41ms)15572026/08/06 11:09:54 goose: successfully migrated database to version: 2026062812000015582026/08/06 11:09:54 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"15592026/08/06 11:09:54 INFO Received uploads request method=POST path=/api/pending_closures15602026/08/06 11:09:54 OK 1_commit_pending_closure.sql (1.92ms)15612026/08/06 11:09:54 OK 20260628120000_add_object_size_and_stats.sql (2.71ms)15622026/08/06 11:09:54 goose: successfully migrated database to version: 2026062812000015632026/08/06 11:09:54 OK 2_object_stats_trigger.sql (651.39µs)15642026/08/06 11:09:54 goose: up to current file version: 215652026/08/06 11:09:54 OK 1_commit_pending_closure.sql (6.48ms)1566=== NAME TestClientCADerivations1567 client_ca_test.go:139: Found 1 dependencies (including self)15682026/08/06 11:09:54 INFO Received uploads request method=POST path=/api/pending_closures15692026/08/06 11:09:54 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15702026/08/06 11:09:54 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-config15712026/08/06 11:09:54 INFO Uploading bgcjg8x79sh0nkb1c9b7b4s331dvr56x-test-script (136B)15722026/08/06 11:09:54 OK 2_object_stats_trigger.sql (1.11ms)15732026/08/06 11:09:54 goose: up to current file version: 215742026/08/06 11:09:54 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15752026/08/06 11:09:54 INFO Uploading 4lbdfg87anapnzi7xznh9dr1vp8lzjnd-test-file.txt (152B)15762026/08/06 11:09:54 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"15772026/08/06 11:09:54 WARN Failed to register uploaded object key=log/23610s2ysq2424hdsjvm88gryi9zq127-test-script.drv error="server returned 404: 404 page not found\n"15782026/08/06 11:09:54 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"15792026/08/06 11:09:54 WARN Failed to register uploaded object key=bgcjg8x79sh0nkb1c9b7b4s331dvr56x.ls error="server returned 404: 404 page not found\n"15802026/08/06 11:09:54 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"15812026/08/06 11:09:54 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign15822026/08/06 11:09:54 INFO Signed narinfos id=1 count=115832026/08/06 11:09:54 INFO Uploading 1 narinfos15842026/08/06 11:09:54 WARN Failed to register uploaded object key=4lbdfg87anapnzi7xznh9dr1vp8lzjnd.ls error="server returned 404: 404 page not found\n"15852026/08/06 11:09:54 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign15862026/08/06 11:09:54 INFO Signed narinfos id=1 count=115872026/08/06 11:09:54 INFO Uploading 1 narinfos15882026/08/06 11:09:54 WARN Failed to register uploaded object key=bgcjg8x79sh0nkb1c9b7b4s331dvr56x.narinfo error="server returned 404: 404 page not found\n"15892026/08/06 11:09:54 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete15902026/08/06 11:09:54 WARN Failed to register uploaded object key=4lbdfg87anapnzi7xznh9dr1vp8lzjnd.narinfo error="server returned 404: 404 page not found\n"15912026/08/06 11:09:54 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete15922026/08/06 11:09:54 INFO Completed upload id=115932026/08/06 11:09:54 INFO Upload complete. (59ms)15942026/08/06 11:09:54 INFO Completed upload id=115952026/08/06 11:09:54 INFO Upload complete. (93ms)1596=== NAME TestClientIntegration1597 client_integration_test.go:292: Retrieved narinfo from S3:1598 StorePath: /build/TestClientIntegration24793408/002/store/4lbdfg87anapnzi7xznh9dr1vp8lzjnd-test-file.txt1599 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1600 Compression: zstd1601 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11602 NarSize: 1521603 References: 1604 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11605=== NAME TestClientWithDependencies1606 client_integration_test.go:597: Skipping nix copy test - isolated store (/build/TestClientWithDependencies575609811/001/store) requires matching store prefix1607=== NAME TestClientIntegration1608 client_integration_test.go:293: Retrieved .ls file from S3 (compressed size: 77 bytes)1609 client_integration_test.go:293: Decompressed .ls content (64 bytes):1610 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1611 client_integration_test.go:296: Testing garbage collection...16122026/08/06 11:09:54 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"1613--- PASS: TestClientWithDependencies (0.38s)16142026/08/06 11:09:55 INFO Received uploads request method=POST path=/api/pending_closures16152026/08/06 11:09:55 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"16162026/08/06 11:09:55 INFO Received uploads request method=POST path=/api/pending_closures16172026/08/06 11:09:55 INFO Received uploads request method=POST path=/api/pending_closures16182026/08/06 11:09:55 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)16192026/08/06 11:09:55 INFO Uploading w6g8qv2860n2jzjh6f4yxaxx7gg5m4ig-test-file-0.txt (160B)16202026/08/06 11:09:55 INFO Uploading gx9pp3v93qh0vg31yb7s9rkm0wfagylh-test-file-2.txt (160B)16212026/08/06 11:09:55 INFO Uploading m0an6afz7y6wkhl00mlr6pi5cs4w3qa3-test-file-1.txt (160B)16222026/08/06 11:09:55 INFO Received uploads request method=POST path=/api/pending_closures16232026/08/06 11:09:55 INFO Starting cleanup of old closures method=DELETE path=/api/closures16242026/08/06 11:09:55 INFO Garbage collection started16252026/08/06 11:09:55 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)16262026/08/06 11:09:55 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"16272026/08/06 11:09:55 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"16282026/08/06 11:09:55 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"16292026/08/06 11:09:55 WARN Failed to register uploaded object key=d37i3h05q3sa21l91hi1n93gx1xgzxdh.ls error="server returned 404: 404 page not found\n"16302026/08/06 11:09:55 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign16312026/08/06 11:09:55 INFO Aborted multipart uploads count=016322026/08/06 11:09:55 INFO Signed narinfos id=2 count=116332026/08/06 11:09:55 INFO Uploading 1 narinfos16342026/08/06 11:09:55 WARN Failed to register uploaded object key=gx9pp3v93qh0vg31yb7s9rkm0wfagylh.ls error="server returned 404: 404 page not found\n"16352026/08/06 11:09:55 WARN Failed to register uploaded object key=w6g8qv2860n2jzjh6f4yxaxx7gg5m4ig.ls error="server returned 404: 404 page not found\n"16362026/08/06 11:09:55 WARN Failed to register uploaded object key=m0an6afz7y6wkhl00mlr6pi5cs4w3qa3.ls error="server returned 404: 404 page not found\n"16372026/08/06 11:09:55 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign16382026/08/06 11:09:55 INFO Signed narinfos id=1 count=116392026/08/06 11:09:55 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign16402026/08/06 11:09:55 INFO Signed narinfos id=2 count=116412026/08/06 11:09:55 WARN Failed to register uploaded object key=d37i3h05q3sa21l91hi1n93gx1xgzxdh.narinfo error="server returned 404: 404 page not found\n"16422026/08/06 11:09:55 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete16432026/08/06 11:09:55 INFO Received sign narinfos request method=POST path=/api/pending_closures/3/sign16442026/08/06 11:09:55 INFO Signed narinfos id=3 count=116452026/08/06 11:09:55 INFO Uploading 3 narinfos16462026/08/06 11:09:55 WARN Force mode enabled - objects will be deleted immediately without grace period16472026/08/06 11:09:55 INFO Completed upload id=216482026/08/06 11:09:55 INFO Upload complete. (72ms)1649=== NAME TestNARDeduplicationMetadataUploadBug1650 metadata_upload_test.go:76: Retrieved narinfo from S3:1651 StorePath: /build/TestNARDeduplicationMetadataUploadBug2814272601/001/store/d37i3h05q3sa21l91hi1n93gx1xgzxdh-file2.txt1652 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1653 Compression: zstd1654 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1655 NarSize: 1601656 References: 1657 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf16582026/08/06 11:09:55 WARN Failed to register uploaded object key=gx9pp3v93qh0vg31yb7s9rkm0wfagylh.narinfo error="server returned 404: 404 page not found\n"16592026/08/06 11:09:55 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"16602026/08/06 11:09:55 WARN Failed to register uploaded object key=m0an6afz7y6wkhl00mlr6pi5cs4w3qa3.narinfo error="server returned 404: 404 page not found\n"16612026/08/06 11:09:55 WARN Failed to register uploaded object key=w6g8qv2860n2jzjh6f4yxaxx7gg5m4ig.narinfo error="server returned 404: 404 page not found\n"16622026/08/06 11:09:55 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete1663 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1664 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1665 {"version":1,"root":{"type":"regular","size":44}}16662026/08/06 11:09:55 INFO Completed upload id=11667--- PASS: TestNARDeduplicationMetadataUploadBug (0.85s)16682026/08/06 11:09:55 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete16692026/08/06 11:09:55 INFO Completed upload id=216702026/08/06 11:09:55 INFO Received complete upload request method=POST path=/api/pending_closures/3/complete16712026/08/06 11:09:55 INFO Completed upload id=316722026/08/06 11:09:55 INFO Upload complete. (109ms)1673=== NAME TestClientMultipleUploads1674 client_integration_test.go:349: Uploaded 3 paths in 136.570894ms16752026/08/06 11:09:55 INFO Received uploads request method=POST path=/api/pending_closures16762026/08/06 11:09:55 INFO Received complete multipart upload request method=POST path=/api/multipart/complete16772026/08/06 11:09:55 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)16782026/08/06 11:09:55 INFO Uploading 97xgimpn6bch4bw49vdnx56h7q3zcvv6-pinned-file.txt (128B)1679--- PASS: TestGCBugBareHashReferences (0.42s)16802026/08/06 11:09:55 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"16812026/08/06 11:09:55 WARN Failed to register uploaded object key=97xgimpn6bch4bw49vdnx56h7q3zcvv6.ls error="server returned 404: 404 page not found\n"16822026/08/06 11:09:55 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign16832026/08/06 11:09:55 INFO Signed narinfos id=1 count=116842026/08/06 11:09:55 INFO Uploading 1 narinfos1685--- PASS: TestClientMultipleUploads (0.44s)16862026/08/06 11:09:55 WARN Failed to register uploaded object key=97xgimpn6bch4bw49vdnx56h7q3zcvv6.narinfo error="server returned 404: 404 page not found\n"16872026/08/06 11:09:55 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete16882026/08/06 11:09:55 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=ZDUyOWY2YWYtYjVjMC00NGMxLWJkZGYtYTMzOGUwZmJmNGRlLmJhMTQxNTk5LWU1MzItNGNiNi1hMWMyLWU4ODdkOGE4ZjlmNngxNzg2MDE0NTk0Njk4OTkzODUw parts=1016892026/08/06 11:09:55 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete16902026/08/06 11:09:55 INFO Completed upload id=116912026/08/06 11:09:55 INFO Upload complete. (83ms)16922026/08/06 11:09:55 INFO Completed upload id=116932026/08/06 11:09:55 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000016942026/08/06 11:09:55 INFO Received uploads request method=POST path=/api/pending_closures16952026/08/06 11:09:55 INFO Starting cleanup of old closures method=DELETE path=/api/closures16962026/08/06 11:09:55 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=209.935773ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config16972026/08/06 11:09:55 INFO Received uploads request method=POST path=/api/pending_closures16982026/08/06 11:09:55 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)16992026/08/06 11:09:55 INFO Uploading fjpf2cdlzh9n9r1n3kh3a7rdqicz5qgj-ca-test (144B)17002026/08/06 11:09:55 INFO Aborted multipart uploads count=017012026/08/06 11:09:55 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"17022026/08/06 11:09:55 WARN Failed to register uploaded object key=log/cn997rkhcw2a7g0gb5z8z0phfbvnx792-ca-test.drv error="server returned 404: 404 page not found\n"1703=== NAME TestOrphanedObjectsGC1704 orphaned_objects_gc_test.go:290: GC Test Summary:1705 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A1706 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B1707 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)1708 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)1709 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects1710--- PASS: TestOrphanedObjectsGC (0.48s)17112026/08/06 11:09:55 WARN Failed to register uploaded object key=fjpf2cdlzh9n9r1n3kh3a7rdqicz5qgj.ls error="server returned 404: 404 page not found\n"17122026/08/06 11:09:55 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign17132026/08/06 11:09:55 INFO Signed narinfos id=1 count=117142026/08/06 11:09:55 INFO Uploading 1 narinfos17152026/08/06 11:09:55 WARN Failed to register uploaded object key=fjpf2cdlzh9n9r1n3kh3a7rdqicz5qgj.narinfo error="server returned 404: 404 page not found\n"17162026/08/06 11:09:55 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete17172026/08/06 11:09:55 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=017182026/08/06 11:09:55 INFO Vacuumed table table=pending_closures17192026/08/06 11:09:55 INFO Vacuumed table table=pending_objects17202026/08/06 11:09:55 INFO Completed upload id=117212026/08/06 11:09:55 INFO Upload complete. (92ms)17222026/08/06 11:09:55 INFO Vacuumed table table=multipart_uploads17232026/08/06 11:09:55 INFO Vacuumed table table=closures1724=== NAME TestClientCADerivations1725 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations112306268/001/store/fjpf2cdlzh9n9r1n3kh3a7rdqicz5qgj-ca-test1726 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1727 Compression: zstd1728 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1729 NarSize: 1441730 References: 17312026/08/06 11:09:55 INFO Vacuumed table table=objects1732 Deriver: /build/TestClientCADerivations112306268/001/store/cn997rkhcw2a7g0gb5z8z0phfbvnx792-ca-test.drv1733 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1734 client_ca_test.go:185: Checking for realisation files in S3...1735 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1736 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache17372026/08/06 11:09:55 INFO Received complete multipart upload request method=POST path=/api/multipart/complete17382026/08/06 11:09:55 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"17392026/08/06 11:09:55 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=ZDUyOWY2YWYtYjVjMC00NGMxLWJkZGYtYTMzOGUwZmJmNGRlLmYwMzEzZGY0LTgyYjktNDBjMC04MjlhLTE0MjZkNmJjNTRhOXgxNzg2MDE0NTk0NjYwNTYxNDA4 parts=121740--- PASS: TestRedundantMultipartUpload (0.92s)17412026/08/06 11:09:55 INFO Received complete multipart upload request method=POST path=/api/multipart/complete17422026/08/06 11:09:55 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001743--- PASS: TestService_createPendingClosureHandler (0.59s)17442026/08/06 11:09:55 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"17452026/08/06 11:09:55 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=ZDUyOWY2YWYtYjVjMC00NGMxLWJkZGYtYTMzOGUwZmJmNGRlLjdlNGY0NGNmLWM0MzMtNDg3My05MGUwLTdlYmU2Y2E3NWU5ZngxNzg2MDE0NTk0NzI4NTczNTI2 parts=1217462026/08/06 11:09:55 INFO Received uploads request method=POST path=/api/pending_closures1747--- PASS: TestCompletedNarNotReofferedAcrossClosures (1.01s)17482026/08/06 11:09:55 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"17492026/08/06 11:09:55 INFO Received uploads request method=POST path=/api/pending_closures17502026/08/06 11:09:55 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)17512026/08/06 11:09:55 INFO Uploading lv51rrh94mx4328fsks8lsqdpz2kkflc-unpinned-file.txt (128B)17522026/08/06 11:09:55 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"17532026/08/06 11:09:55 WARN Failed to register uploaded object key=lv51rrh94mx4328fsks8lsqdpz2kkflc.ls error="server returned 404: 404 page not found\n"17542026/08/06 11:09:55 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign17552026/08/06 11:09:55 INFO Signed narinfos id=2 count=117562026/08/06 11:09:55 INFO Uploading 1 narinfos17572026/08/06 11:09:55 WARN Failed to register uploaded object key=lv51rrh94mx4328fsks8lsqdpz2kkflc.narinfo error="server returned 404: 404 page not found\n"17582026/08/06 11:09:55 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete17592026/08/06 11:09:55 INFO Completed upload id=217602026/08/06 11:09:55 INFO Upload complete. (67ms)17612026/08/06 11:09:55 INFO Received create pin request method=POST path=/api/pins/myapp17622026/08/06 11:09:55 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC673262370/001/store/97xgimpn6bch4bw49vdnx56h7q3zcvv6-pinned-file.txt narinfo_key=97xgimpn6bch4bw49vdnx56h7q3zcvv6.narinfo17632026/08/06 11:09:55 INFO Starting cleanup of old closures method=DELETE path=/api/closures17642026/08/06 11:09:55 INFO Garbage collection started17652026/08/06 11:09:55 INFO Aborted multipart uploads count=017662026/08/06 11:09:55 WARN Force mode enabled - objects will be deleted immediately without grace period17672026/08/06 11:09:55 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=017682026/08/06 11:09:55 INFO Vacuumed table table=pending_closures17692026/08/06 11:09:55 INFO Vacuumed table table=pending_objects17702026/08/06 11:09:55 INFO Vacuumed table table=multipart_uploads17712026/08/06 11:09:55 INFO Vacuumed table table=closures17722026/08/06 11:09:55 INFO Vacuumed table table=objects1773=== NAME TestClientCADerivations1774 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features1775 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable1776 error: binary cache 's3://bucket38?endpoint=http://localhost:41817®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations112306268/001/store'1777 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 11778--- PASS: TestClientCADerivations (0.60s)17792026/08/06 11:09:55 INFO Received complete multipart upload request method=POST path=/api/multipart/complete17802026/08/06 11:09:55 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=ZDUyOWY2YWYtYjVjMC00NGMxLWJkZGYtYTMzOGUwZmJmNGRlLjJkMWM2ODg4LTNiOTEtNGY2Mi1iM2ZjLTRhMWU1ZDg4NzJlZngxNzg2MDE0NTk0OTQ4MjU5MTkw parts=1017812026/08/06 11:09:55 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete17822026/08/06 11:09:55 INFO Completed upload id=117832026/08/06 11:09:55 INFO Received uploads request method=POST path=/api/pending_closures17842026/08/06 11:09:55 INFO Received uploads request method=POST path=/api/pending_closures17852026/08/06 11:09:55 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo17862026/08/06 11:09:55 WARN Found objects in DB but missing from S3, will re-upload count=11787--- PASS: TestService_verifyS3Integrity (1.07s)17882026/08/06 11:09:55 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=429.948394ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config17892026/08/06 11:09:55 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=017902026/08/06 11:09:55 INFO Vacuumed table table=pending_closures17912026/08/06 11:09:55 INFO Vacuumed table table=pending_objects17922026/08/06 11:09:55 INFO Vacuumed table table=multipart_uploads17932026/08/06 11:09:55 INFO Vacuumed table table=closures17942026/08/06 11:09:55 INFO Vacuumed table table=objects1795--- PASS: TestUploadHandlersRejectOversizedBody (0.23s)1796 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.05s)1797 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.06s)1798 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.84s)1799=== NAME TestOrphanedObjectsGCStressTest1800 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains1801 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion18022026/08/06 11:09:55 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=815.996765ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config1803 orphaned_objects_gc_test.go:509: Stress test completed successfully:1804 orphaned_objects_gc_test.go:510: - Active objects preserved: 201805 orphaned_objects_gc_test.go:511: - Objects deleted: 2101806 orphaned_objects_gc_test.go:512: - Total GC'd: 2101807--- PASS: TestOrphanedObjectsGCStressTest (1.52s)18082026/08/06 11:09:56 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.448233831s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config18092026/08/06 11:09:57 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=01810=== NAME TestClientIntegration1811 client_integration_test.go:303: Objects in database after GC:1812 client_integration_test.go:303: Successfully deleted all objects with GC --force1813--- PASS: TestClientIntegration (2.40s)18142026/08/06 11:09:57 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=01815=== NAME TestPinProtectsFromGC1816 client_integration_test.go:709: Pin successfully protected closure from garbage collection1817--- PASS: TestPinProtectsFromGC (2.46s)18182026/08/06 11:09:57 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"18192026/08/06 11:09:58 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_closures18202026/08/06 11:09:58 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=212.602309ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures18212026/08/06 11:09:58 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=438.843275ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures18222026/08/06 11:09:58 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=835.704323ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures18232026/08/06 11:09:59 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.602678226s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures18242026/08/06 11:09:59 WARN Rate limiter enabled after throttle name=s3-test rate=518252026/08/06 11:09:59 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."1826=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle1827 throttle_test.go:213: Proxy stats: total=15, throttled=10, completeMultipart=101828 throttle_test.go:215: Rate limiter: enabled=true, rate=5.001829--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (5.73s)1830--- PASS: TestClientErrorHandling (0.00s)1831 --- PASS: TestClientErrorHandling/InvalidStorePath (0.17s)1832 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.29s)1833 --- PASS: TestClientErrorHandling/ServerNotAvailable (6.36s)1834PASS18352026-08-06 11:10:01.391 UTC [113] LOG: received smart shutdown request18362026-08-06 11:10:01.394 UTC [113] LOG: background worker "logical replication launcher" (PID 123) exited with exit code 118372026-08-06 11:10:01.402 UTC [118] LOG: shutting down18382026-08-06 11:10:01.402 UTC [118] LOG: checkpoint starting: shutdown immediate18392026-08-06 11:10:02.263 UTC [118] LOG: checkpoint complete: wrote 11462 buffers (70.0%), wrote 3 SLRU buffers; 0 WAL file(s) added, 0 removed, 13 recycled; write=0.182 s, sync=0.670 s, total=0.862 s; sync files=15167, longest=0.004 s, average=0.001 s; distance=208934 kB, estimate=208934 kB; lsn=0/E36D6A0, redo lsn=0/E36D6A018402026-08-06 11:10:02.318 UTC [113] LOG: database system is shut down1841Running OIDC tests...1842=== RUN TestGlobMatch1843=== PAUSE TestGlobMatch1844=== RUN TestAudienceForIssuer1845=== PAUSE TestAudienceForIssuer1846=== RUN TestValidateToken_ValidToken1847=== PAUSE TestValidateToken_ValidToken1848=== RUN TestValidateToken_WrongAudience1849=== PAUSE TestValidateToken_WrongAudience1850=== RUN TestValidateToken_Expired1851=== PAUSE TestValidateToken_Expired1852=== RUN TestValidateToken_BoundClaimsMismatch1853=== PAUSE TestValidateToken_BoundClaimsMismatch1854=== RUN TestValidateToken_BoundSubjectMismatch1855=== PAUSE TestValidateToken_BoundSubjectMismatch1856=== RUN TestValidateToken_MultipleProviders1857=== PAUSE TestValidateToken_MultipleProviders1858=== RUN TestValidateToken_NoMatchingProvider1859=== PAUSE TestValidateToken_NoMatchingProvider1860=== CONT TestGlobMatch1861=== RUN TestGlobMatch/foo_foo1862=== CONT TestValidateToken_BoundClaimsMismatch1863=== CONT TestValidateToken_WrongAudience1864=== CONT TestValidateToken_MultipleProviders1865=== PAUSE TestGlobMatch/foo_foo1866=== RUN TestGlobMatch/foo_bar1867=== PAUSE TestGlobMatch/foo_bar1868=== RUN TestGlobMatch/*_1869=== CONT TestValidateToken_ValidToken1870=== CONT TestAudienceForIssuer1871=== CONT TestValidateToken_Expired1872=== CONT TestValidateToken_NoMatchingProvider1873=== CONT TestValidateToken_BoundSubjectMismatch1874=== PAUSE TestGlobMatch/*_1875=== RUN TestGlobMatch/*_anything1876=== PAUSE TestGlobMatch/*_anything1877=== RUN TestGlobMatch/foo*_foo1878=== PAUSE TestGlobMatch/foo*_foo1879--- PASS: TestAudienceForIssuer (0.00s)1880=== RUN TestGlobMatch/foo*_foobar1881=== PAUSE TestGlobMatch/foo*_foobar1882=== RUN TestGlobMatch/foo*_bar1883=== PAUSE TestGlobMatch/foo*_bar1884=== RUN TestGlobMatch/*bar_bar1885=== PAUSE TestGlobMatch/*bar_bar1886=== RUN TestGlobMatch/*bar_foobar1887=== PAUSE TestGlobMatch/*bar_foobar1888=== RUN TestGlobMatch/*bar_foo1889=== PAUSE TestGlobMatch/*bar_foo1890=== RUN TestGlobMatch/foo*bar_foobar1891=== PAUSE TestGlobMatch/foo*bar_foobar1892=== RUN TestGlobMatch/foo*bar_foo123bar1893=== PAUSE TestGlobMatch/foo*bar_foo123bar1894=== RUN TestGlobMatch/foo*bar_foobarbaz1895=== PAUSE TestGlobMatch/foo*bar_foobarbaz1896=== RUN TestGlobMatch/*/*_foo/bar1897=== PAUSE TestGlobMatch/*/*_foo/bar1898=== RUN TestGlobMatch/*/*_foo1899=== PAUSE TestGlobMatch/*/*_foo1900=== RUN TestGlobMatch/refs/heads/*_refs/heads/main1901=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main1902=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.01903=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.01904=== RUN TestGlobMatch/refs/*/main_refs/heads/main1905=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main1906=== RUN TestGlobMatch/fo?_foo1907=== PAUSE TestGlobMatch/fo?_foo1908=== RUN TestGlobMatch/fo?_fo1909=== PAUSE TestGlobMatch/fo?_fo1910=== RUN TestGlobMatch/fo?_fooo1911=== PAUSE TestGlobMatch/fo?_fooo1912=== RUN TestGlobMatch/?oo_foo1913=== PAUSE TestGlobMatch/?oo_foo1914=== RUN TestGlobMatch/?oo_boo1915=== PAUSE TestGlobMatch/?oo_boo1916=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main1917=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main1918=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main1919=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main1920=== CONT TestGlobMatch/foo_foo1921=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main1922=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main1923=== CONT TestGlobMatch/*bar_foo1924=== CONT TestGlobMatch/*/*_foo1925=== CONT TestGlobMatch/*/*_foo/bar1926=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.01927=== CONT TestGlobMatch/*bar_foobar1928=== CONT TestGlobMatch/*bar_bar1929=== CONT TestGlobMatch/*_anything1930=== CONT TestGlobMatch/foo*bar_foobarbaz1931=== CONT TestGlobMatch/foo*bar_foo123bar1932=== CONT TestGlobMatch/?oo_boo1933=== CONT TestGlobMatch/foo*bar_foobar1934=== CONT TestGlobMatch/?oo_foo1935=== CONT TestGlobMatch/foo*_foobar1936=== CONT TestGlobMatch/foo*_bar1937=== CONT TestGlobMatch/fo?_fooo1938=== CONT TestGlobMatch/*_1939=== CONT TestGlobMatch/fo?_fo1940=== CONT TestGlobMatch/foo*_foo1941=== CONT TestGlobMatch/fo?_foo1942=== CONT TestGlobMatch/foo_bar1943=== CONT TestGlobMatch/refs/*/main_refs/heads/main1944=== CONT TestGlobMatch/refs/heads/*_refs/heads/main1945--- PASS: TestGlobMatch (0.00s)1946 --- PASS: TestGlobMatch/foo_foo (0.00s)1947 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)1948 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)1949 --- PASS: TestGlobMatch/*bar_foo (0.00s)1950 --- PASS: TestGlobMatch/*/*_foo (0.00s)1951 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)1952 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)1953 --- PASS: TestGlobMatch/*bar_foobar (0.00s)1954 --- PASS: TestGlobMatch/*bar_bar (0.00s)1955 --- PASS: TestGlobMatch/*_anything (0.00s)1956 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)1957 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)1958 --- PASS: TestGlobMatch/?oo_boo (0.00s)1959 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)1960 --- PASS: TestGlobMatch/?oo_foo (0.00s)1961 --- PASS: TestGlobMatch/foo*_foobar (0.00s)1962 --- PASS: TestGlobMatch/foo*_bar (0.00s)1963 --- PASS: TestGlobMatch/fo?_fooo (0.00s)1964 --- PASS: TestGlobMatch/*_ (0.00s)1965 --- PASS: TestGlobMatch/fo?_fo (0.00s)1966 --- PASS: TestGlobMatch/foo*_foo (0.00s)1967 --- PASS: TestGlobMatch/fo?_foo (0.00s)1968 --- PASS: TestGlobMatch/foo_bar (0.00s)1969 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)1970 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)19712026/08/06 11:10:03 INFO OIDC provider initialized name=provider119722026/08/06 11:10:03 INFO OIDC provider initialized name=test19732026/08/06 11:10:03 INFO OIDC provider initialized name=provider119742026/08/06 11:10:03 INFO OIDC provider initialized name=test19752026/08/06 11:10:03 INFO OIDC provider initialized name=test19762026/08/06 11:10:03 INFO OIDC provider initialized name=test19772026/08/06 11:10:03 INFO OIDC provider initialized name=test19782026/08/06 11:10:03 INFO OIDC provider initialized name=provider21979--- PASS: TestValidateToken_WrongAudience (0.01s)1980--- PASS: TestValidateToken_ValidToken (0.01s)1981--- PASS: TestValidateToken_BoundSubjectMismatch (0.01s)1982--- PASS: TestValidateToken_BoundClaimsMismatch (0.01s)1983--- PASS: TestValidateToken_Expired (0.01s)1984--- PASS: TestValidateToken_NoMatchingProvider (0.01s)1985--- PASS: TestValidateToken_MultipleProviders (0.01s)1986PASS1987Running hook tests...1988=== RUN TestSendPathsEmpty1989=== PAUSE TestSendPathsEmpty1990=== RUN TestQueueEnqueueAndFetch1991=== PAUSE TestQueueEnqueueAndFetch1992=== RUN TestQueueDeduplication1993=== PAUSE TestQueueDeduplication1994=== RUN TestQueueRemove1995=== PAUSE TestQueueRemove1996=== RUN TestQueueFetchBatchLimit1997=== PAUSE TestQueueFetchBatchLimit1998=== RUN TestQueueFetchRemoveLifecycle1999=== PAUSE TestQueueFetchRemoveLifecycle2000=== RUN TestQueueConcurrentWriters2001=== PAUSE TestQueueConcurrentWriters2002=== RUN TestServerClientIntegration2003=== PAUSE TestServerClientIntegration2004=== RUN TestServerQueueError2005=== PAUSE TestServerQueueError2006=== RUN TestGetListenerSocketActivation2007 server_test.go:210: === RUN TestGetListenerSocketActivation2008 --- PASS: TestGetListenerSocketActivation (0.00s)2009 PASS2010 2011--- PASS: TestGetListenerSocketActivation (0.01s)2012=== RUN TestWorkerUploadsAndRemoves2013=== PAUSE TestWorkerUploadsAndRemoves2014=== RUN TestWorkerSkipsGCdPaths2015=== PAUSE TestWorkerSkipsGCdPaths2016=== RUN TestWorkerPrunesClosureDeps2017=== PAUSE TestWorkerPrunesClosureDeps2018=== CONT TestSendPathsEmpty2019=== CONT TestWorkerPrunesClosureDeps2020=== CONT TestQueueEnqueueAndFetch2021=== CONT TestWorkerSkipsGCdPaths2022=== CONT TestQueueDeduplication2023=== CONT TestServerClientIntegration2024=== CONT TestServerQueueError2025=== CONT TestQueueRemove2026=== CONT TestQueueFetchRemoveLifecycle2027=== CONT TestQueueConcurrentWriters2028=== CONT TestQueueFetchBatchLimit2029=== CONT TestWorkerUploadsAndRemoves2030--- PASS: TestSendPathsEmpty (0.00s)20312026/08/06 11:10:03 ERROR Failed to queue paths error="permission denied" count=12032--- PASS: TestServerClientIntegration (0.00s)2033--- PASS: TestServerQueueError (0.00s)2034--- PASS: TestQueueDeduplication (0.02s)20352026/08/06 11:10:03 INFO Upload queue status pending=220362026/08/06 11:10:03 INFO Uploading batch count=12037--- PASS: TestQueueEnqueueAndFetch (0.02s)20382026/08/06 11:10:03 INFO Upload queue status pending=220392026/08/06 11:10:03 INFO Uploading batch count=22040--- PASS: TestQueueFetchBatchLimit (0.02s)2041--- PASS: TestQueueFetchRemoveLifecycle (0.02s)20422026/08/06 11:10:03 INFO Upload queue status pending=220432026/08/06 11:10:03 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerSkipsGCdPaths627769466/002/nonexistent2044--- PASS: TestQueueRemove (0.02s)20452026/08/06 11:10:03 INFO Uploading batch count=12046--- PASS: TestWorkerPrunesClosureDeps (0.07s)2047--- PASS: TestWorkerUploadsAndRemoves (0.07s)2048--- PASS: TestWorkerSkipsGCdPaths (0.07s)2049--- PASS: TestQueueConcurrentWriters (0.27s)2050PASS