niks3-go-unit-tests
checks.x86_64-linux.go-unit-tests
· build #196
· 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 TestDumpPathCaseHackMatchesNix14--- PASS: TestDumpPathCaseHackMatchesNix (0.03s)15=== RUN TestDumpPathCaseHackCollision16--- PASS: TestDumpPathCaseHackCollision (0.00s)17=== RUN TestDumpPathMatchesNix18=== PAUSE TestDumpPathMatchesNix19=== RUN TestDumpPathSingleFile20=== PAUSE TestDumpPathSingleFile21=== RUN TestDumpPathWriterError22=== PAUSE TestDumpPathWriterError23=== RUN TestEncodeNixBase3224=== PAUSE TestEncodeNixBase3225=== RUN TestEncodeNixBase32WithRealHash26=== PAUSE TestEncodeNixBase32WithRealHash27=== RUN TestConvertHashToNix3228=== PAUSE TestConvertHashToNix3229=== RUN TestGetStorePathHash30=== PAUSE TestGetStorePathHash31=== RUN TestPathInfoHashCompatibility32=== PAUSE TestPathInfoHashCompatibility33=== RUN TestParsePathInfoJSON34=== PAUSE TestParsePathInfoJSON35=== RUN TestParsePathInfoJSONMultiplePaths36=== PAUSE TestParsePathInfoJSONMultiplePaths37=== RUN TestPathInfoCACompatibility38=== PAUSE TestPathInfoCACompatibility39=== RUN TestRateLimiterFeedback40=== PAUSE TestRateLimiterFeedback41=== RUN TestRateLimiterFeedback_400DoesNotCountAsSuccess42=== PAUSE TestRateLimiterFeedback_400DoesNotCountAsSuccess43=== RUN TestResolveStorePath44=== PAUSE TestResolveStorePath45=== RUN TestDoWithRetry_BodyReplayedViaGetBody46=== PAUSE TestDoWithRetry_BodyReplayedViaGetBody47=== RUN TestShellSplit48=== PAUSE TestShellSplit49=== RUN TestShellSplitErrors50=== PAUSE TestShellSplitErrors51=== RUN TestStreamPushReportsEveryPath52=== PAUSE TestStreamPushReportsEveryPath53=== RUN TestStreamPushBatchesUnderLoad54=== PAUSE TestStreamPushBatchesUnderLoad55=== RUN TestStreamPushIsolatesFailures56=== PAUSE TestStreamPushIsolatesFailures57=== RUN TestStreamPushGivesUpOnDeadServer58=== PAUSE TestStreamPushGivesUpOnDeadServer59=== RUN TestSetClientTLS60=== PAUSE TestSetClientTLS61=== RUN TestSetClientTLSDoesNotMutateDefaultTransport62=== PAUSE TestSetClientTLSDoesNotMutateDefaultTransport63=== RUN TestSetClientTLSErrors64=== PAUSE TestSetClientTLSErrors65=== RUN TestStaticToken66=== PAUSE TestStaticToken67=== RUN TestFileTokenReadsAndCaches68=== PAUSE TestFileTokenReadsAndCaches69=== RUN TestFileTokenMissing70=== PAUSE TestFileTokenMissing71=== RUN TestFileTokenEmpty72=== PAUSE TestFileTokenEmpty73=== RUN TestScriptTokenNoExpiryRerunsEveryCall74=== PAUSE TestScriptTokenNoExpiryRerunsEveryCall75=== RUN TestScriptTokenCachesUntilRefresh76=== PAUSE TestScriptTokenCachesUntilRefresh77=== RUN TestScriptTokenEmptyToken78=== PAUSE TestScriptTokenEmptyToken79=== RUN TestScriptTokenBadJSON80=== PAUSE TestScriptTokenBadJSON81=== RUN TestScriptTokenScriptFails82=== PAUSE TestScriptTokenScriptFails83=== RUN TestScriptTokenEmptyCommand84=== PAUSE TestScriptTokenEmptyCommand85=== CONT TestDoServerRequestAttachesToken86=== CONT TestConvertHashToNix3287=== CONT TestFileTokenReadsAndCaches88=== CONT TestScriptTokenScriptFails89=== CONT TestGetStorePathHash90=== CONT TestStaticToken91=== CONT TestSetClientTLSErrors92=== CONT TestEncodeNixBase32WithRealHash93=== CONT TestEncodeNixBase3294=== CONT TestSetClientTLSDoesNotMutateDefaultTransport95=== RUN TestEncodeNixBase32/test_string_hash96=== PAUSE TestEncodeNixBase32/test_string_hash97=== RUN TestEncodeNixBase32/empty_input98=== PAUSE TestEncodeNixBase32/empty_input99=== CONT TestDumpPathWriterError100=== CONT TestSetClientTLS101=== CONT TestStreamPushGivesUpOnDeadServer102=== CONT TestStreamPushIsolatesFailures103=== CONT TestStreamPushBatchesUnderLoad104=== CONT TestStreamPushReportsEveryPath105=== CONT TestShellSplitErrors106=== CONT TestPathInfoCACompatibility107=== CONT TestDoWithRetry_BodyReplayedViaGetBody108=== CONT TestDumpPathSingleFile109=== CONT TestResolveStorePath110=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess1112026/09/10 17:38:49 ERROR Upload failed error="bad path" count=3112=== CONT TestRateLimiterFeedback1132026/09/10 17:38:49 ERROR Upload failed error="connection refused" count=20114=== RUN TestRateLimiterFeedback/429_enables_limiter1152026/09/10 17:38:49 WARN Rate limiter enabled after throttle name=server-test rate=51162026/09/10 17:38:49 ERROR Server seems unavailable, giving up on batch untried=17117=== CONT TestParsePathInfoJSON118=== RUN TestParsePathInfoJSON/Nix_format119=== CONT TestParsePathInfoJSONMultiplePaths120=== CONT TestCaseHackSuffix121=== RUN TestConvertHashToNix32/SRI_format_to_Nix32122=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths123=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32124=== CONT TestPathInfoHashCompatibility125=== CONT TestScriptTokenEmptyCommand126=== CONT TestShellSplit127=== RUN TestGetStorePathHash/valid_store_path128--- PASS: TestFileTokenReadsAndCaches (0.00s)129=== CONT TestDumpPathMatchesNix130=== CONT TestPartSizeForNAR131=== RUN TestPathInfoCACompatibility/null_ca_field132=== RUN TestSetClientTLSErrors/missing_cert_file133=== PAUSE TestRateLimiterFeedback/429_enables_limiter134=== CONT TestScriptTokenBadJSON135=== CONT TestFilterOversizedClosures136=== CONT TestUploadMultipart_SupersededByPeer137=== PAUSE TestParsePathInfoJSON/Nix_format138=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths139--- PASS: TestStaticToken (0.00s)140--- PASS: TestEncodeNixBase32WithRealHash (0.00s)141=== RUN TestParsePathInfoJSON/Lix_format142=== PAUSE TestParsePathInfoJSON/Lix_format143=== RUN TestParsePathInfoJSON/empty_input144--- PASS: TestScriptTokenScriptFails (0.00s)1452026/09/10 17:38:49 WARN Rate limiter enabled after throttle name=server-test rate=5146--- PASS: TestShellSplitErrors (0.00s)147=== CONT TestScriptTokenNoExpiryRerunsEveryCall148=== RUN TestPartSizeForNAR/zero_stays_at_minimum1492026/09/10 17:38:49 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:34329150=== PAUSE TestGetStorePathHash/valid_store_path151=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)152=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths153=== RUN TestSetClientTLS/rejects_connection_without_client_cert154=== PAUSE TestPathInfoCACompatibility/null_ca_field155=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths156=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert157=== RUN TestPathInfoCACompatibility/old_string_format_-_text158=== PAUSE TestSetClientTLSErrors/missing_cert_file159=== RUN TestRateLimiterFeedback/503_enables_limiter160=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text161=== CONT TestFileTokenEmpty162=== CONT TestScriptTokenCachesUntilRefresh163=== RUN TestUploadMultipart_SupersededByPeer/exists164=== RUN TestConvertHashToNix32/already_Nix32_format165=== PAUSE TestParsePathInfoJSON/empty_input1662026/09/10 17:38:49 WARN Rate limiter backed off name=server-test rate=5167--- PASS: TestStreamPushReportsEveryPath (0.00s)168=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum1692026/09/10 17:38:49 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:34329170=== RUN TestFilterOversizedClosures/no_limit_keeps_everything171=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)172=== CONT TestFileTokenMissing173=== RUN TestGetStorePathHash/basename_without_hyphen_should_error174=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA175=== RUN TestSetClientTLSErrors/missing_key_file176=== PAUSE TestRateLimiterFeedback/503_enables_limiter177=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive178--- PASS: TestStreamPushGivesUpOnDeadServer (0.01s)179=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error180=== PAUSE TestSetClientTLSErrors/missing_key_file181=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA182=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive183--- PASS: TestStreamPushIsolatesFailures (0.01s)184--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.01s)185--- PASS: TestScriptTokenEmptyCommand (0.00s)186--- PASS: TestResolveStorePath (0.00s)187--- PASS: TestShellSplit (0.00s)188--- PASS: TestDoServerRequestAttachesToken (0.02s)189=== PAUSE TestUploadMultipart_SupersededByPeer/exists190=== CONT TestScriptTokenEmptyToken191=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything192=== PAUSE TestConvertHashToNix32/already_Nix32_format193=== RUN TestParsePathInfoJSON/whitespace_only194=== PAUSE TestParsePathInfoJSON/whitespace_only195=== RUN TestParsePathInfoJSON/invalid_JSON196=== PAUSE TestParsePathInfoJSON/invalid_JSON197=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter198=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter199=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon200=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon201=== CONT TestEncodeNixBase32/test_string_hash202=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error203=== RUN TestPathInfoCACompatibility/new_structured_format_-_text204=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text205=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped206=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths207=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths208=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error209=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error210=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped211=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method212=== RUN TestSetClientTLSErrors/missing_ca_file213=== RUN TestFilterOversizedClosures/all_closures_skipped214=== RUN TestSetClientTLS/preserves_debug_logging_transport215=== PAUSE TestFilterOversizedClosures/all_closures_skipped216=== CONT TestParsePathInfoJSON/empty_input217=== PAUSE TestSetClientTLSErrors/missing_ca_file218=== RUN TestUploadMultipart_SupersededByPeer/missing219=== RUN TestPartSizeForNAR/small_stays_at_minimum220=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter221=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI222=== RUN TestConvertHashToNix32/invalid_format223--- PASS: TestFileTokenMissing (0.00s)224=== CONT TestParsePathInfoJSON/Nix_format225--- PASS: TestFileTokenEmpty (0.00s)226--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.01s)227--- PASS: TestScriptTokenBadJSON (0.01s)228=== CONT TestParsePathInfoJSON/invalid_JSON229=== CONT TestParsePathInfoJSON/whitespace_only230=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error231=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method232=== PAUSE TestPartSizeForNAR/small_stays_at_minimum233=== CONT TestEncodeNixBase32/empty_input234=== PAUSE TestSetClientTLS/preserves_debug_logging_transport235--- PASS: TestEncodeNixBase32 (0.00s)236 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)237 --- PASS: TestEncodeNixBase32/empty_input (0.00s)238=== CONT TestParsePathInfoJSON/Lix_format239--- PASS: TestParsePathInfoJSONMultiplePaths (0.00s)240 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)241 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)242=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter243=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error244=== CONT TestPathInfoCACompatibility/new_structured_format_-_text245=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive246=== CONT TestPathInfoCACompatibility/old_string_format_-_text247=== PAUSE TestUploadMultipart_SupersededByPeer/missing248=== CONT TestFilterOversizedClosures/all_closures_skipped2492026/09/10 17:38:49 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=50250=== CONT TestRateLimiterFeedback/429_enables_limiter251=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum252=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum253=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts254=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts255=== RUN TestPartSizeForNAR/1_TiB256=== PAUSE TestPartSizeForNAR/1_TiB257=== RUN TestPartSizeForNAR/5_TiB_S3_max_object258=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object259=== RUN TestPartSizeForNAR/capped_at_5_GiB260=== PAUSE TestPartSizeForNAR/capped_at_5_GiB261=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error262=== CONT TestRateLimiterFeedback/503_enables_limiter263=== PAUSE TestConvertHashToNix32/invalid_format264=== CONT TestFilterOversizedClosures/no_limit_keeps_everything265=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter266=== CONT TestUploadMultipart_SupersededByPeer/missing267=== CONT TestUploadMultipart_SupersededByPeer/exists268=== CONT TestGetStorePathHash/basename_without_hyphen_should_error269=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped2702026/09/10 17:38:49 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=20002712026/09/10 17:38:49 WARN Rate limiter enabled after throttle name=server-test rate=52722026/09/10 17:38:49 WARN Rate limiter enabled after throttle name=server-test rate=5273=== CONT TestPartSizeForNAR/capped_at_5_GiB2742026/09/10 17:38:49 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:34011275--- PASS: TestParsePathInfoJSON (0.01s)276 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)277 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)278 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)279 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)280 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)281=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method282=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI283=== CONT TestGetStorePathHash/valid_store_path2842026/09/10 17:38:49 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:36373285=== RUN TestSetClientTLSErrors/invalid_ca_file286=== CONT TestSetClientTLS/rejects_connection_without_client_cert287=== CONT TestSetClientTLS/preserves_debug_logging_transport288=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA289=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter290=== CONT TestPathInfoCACompatibility/null_ca_field291=== CONT TestPartSizeForNAR/5_TiB_S3_max_object292--- PASS: TestScriptTokenEmptyToken (0.00s)293=== CONT TestPartSizeForNAR/1_TiB294=== CONT TestPartSizeForNAR/zero_stays_at_minimum295=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512296=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts297=== PAUSE TestSetClientTLSErrors/invalid_ca_file298=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha5122992026/09/10 17:38:49 WARN Rate limiter backed off name=server-test rate=5300=== CONT TestConvertHashToNix32/SRI_format_to_Nix32301=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum302=== CONT TestPartSizeForNAR/small_stays_at_minimum303=== CONT TestSetClientTLSErrors/invalid_ca_file304=== CONT TestConvertHashToNix32/already_Nix32_format305=== CONT TestConvertHashToNix32/invalid_format306--- PASS: TestGetStorePathHash (0.02s)307 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)308 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)309 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)310 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)311--- PASS: TestFilterOversizedClosures (0.01s)312 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)313 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)314 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)315=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512316--- PASS: TestPartSizeForNAR (0.01s)317 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)318 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)319 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)320 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)321 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)322 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)323 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)324--- PASS: TestConvertHashToNix32 (0.02s)325 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)326 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)327 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)328=== CONT TestSetClientTLSErrors/missing_cert_file329=== CONT TestSetClientTLSErrors/missing_ca_file330=== CONT TestSetClientTLSErrors/missing_key_file331=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)3322026/09/10 17:38:49 WARN Rate limiter backed off name=server-test rate=5333=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon334=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI335--- PASS: TestPathInfoCACompatibility (0.01s)336 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)337 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)338 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)339 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)340 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)341--- PASS: TestPathInfoHashCompatibility (0.01s)342 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)343 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)344 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)345 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)346--- PASS: TestRateLimiterFeedback (0.01s)347 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)348 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)349 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)350 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)351--- PASS: TestSetClientTLSErrors (0.02s)352 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)353 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)354 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)355 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)356--- PASS: TestScriptTokenCachesUntilRefresh (0.01s)357--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.02s)358--- PASS: TestUploadMultipart_SupersededByPeer (0.01s)359 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.01s)360 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.01s)3612026/09/10 17:38:49 http: TLS handshake error from 127.0.0.1:37640: remote error: tls: bad certificate362--- PASS: TestSetClientTLS (0.02s)363 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.00s)364 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.00s)365 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.01s)366--- PASS: TestDumpPathSingleFile (0.03s)367--- PASS: TestDumpPathWriterError (0.04s)368--- PASS: TestCaseHackSuffix (0.04s)369--- PASS: TestDumpPathMatchesNix (0.07s)370--- PASS: TestStreamPushBatchesUnderLoad (0.10s)371--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)372PASS373Running server tests...374The files belonging to this database system will be owned by user "nixbld".375This user must also own the server process.376377The database cluster will be initialized with locale "C".378The default database encoding has accordingly been set to "SQL_ASCII".379The default text search configuration will be set to "english".380381Data page checksums are enabled.382383creating directory /build/postgres1151088887/data ... ok384creating subdirectories ... ok385selecting dynamic shared memory implementation ... posix386selecting default "max_connections" ... 100387selecting default "shared_buffers" ... 128MB388selecting default time zone ... UTC389creating configuration files ... ok390running bootstrap script ... ok391performing post-bootstrap initialization ... ok392syncing data to disk ... ok393394initdb: warning: enabling "trust" authentication for local connections395initdb: 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.396397Success. You can now start the database server using:398399 pg_ctl -D /build/postgres1151088887/data -l logfile start400401/build/postgres1151088887:5432 - no response4022026-09-10 17:38:50.855 UTC [127] LOG: starting PostgreSQL 18.6 on x86_64-pc-linux-gnu, compiled by clang version 21.1.8, 64-bit4032026-09-10 17:38:50.856 UTC [127] LOG: listening on Unix socket "/build/postgres1151088887/.s.PGSQL.5432"4042026-09-10 17:38:50.861 UTC [134] LOG: database system was shut down at 2026-09-10 17:38:50 UTC4052026-09-10 17:38:50.864 UTC [127] LOG: database system is ready to accept connections406/build/postgres1151088887:5432 - accepting connections407=== RUN TestService_AuthMiddleware408=== PAUSE TestService_AuthMiddleware409=== RUN TestService_AuthMiddleware_MTLSProxyHeader410=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader411=== RUN TestService_AuthMiddleware_MTLSBoundSubjects412=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects413=== RUN TestService_ReadAuthMiddleware414=== PAUSE TestService_ReadAuthMiddleware415=== RUN TestService_AuthMiddleware_OIDC416=== PAUSE TestService_AuthMiddleware_OIDC417=== RUN TestService_RequireScope_OIDC418=== PAUSE TestService_RequireScope_OIDC419=== RUN TestService_ReadScope_PublicByDefault420=== PAUSE TestService_ReadScope_PublicByDefault421=== RUN TestCacheConfigHandler422=== PAUSE TestCacheConfigHandler423=== RUN TestCacheStatsHandler424=== PAUSE TestCacheStatsHandler425=== RUN TestClaim_BuildWaitComplete426=== PAUSE TestClaim_BuildWaitComplete427=== RUN TestClaim_GCMarkedOutputCountsAsAbsent428=== PAUSE TestClaim_GCMarkedOutputCountsAsAbsent429=== RUN TestClaim_TooManyStreams430=== PAUSE TestClaim_TooManyStreams431=== RUN TestClaim_HolderDisconnectKeepsClaim432=== PAUSE TestClaim_HolderDisconnectKeepsClaim433=== RUN TestClaim_FailWakesWaitersButIsNotRemembered434=== PAUSE TestClaim_FailWakesWaitersButIsNotRemembered435=== RUN TestClaim_FailWithoutKindReleases436=== PAUSE TestClaim_FailWithoutKindReleases437=== RUN TestClaim_StaleHeartbeatStolen438=== PAUSE TestClaim_StaleHeartbeatStolen439=== RUN TestClaim_TwoInstances440=== PAUSE TestClaim_TwoInstances441=== RUN TestClaim_InputsTouched442=== PAUSE TestClaim_InputsTouched443=== RUN TestClaim_StreamsThroughServer444=== PAUSE TestClaim_StreamsThroughServer445=== RUN TestClientCADerivations446=== PAUSE TestClientCADerivations447=== RUN TestClientErrorHandling448=== PAUSE TestClientErrorHandling449=== RUN TestClientIntegration450=== PAUSE TestClientIntegration451=== RUN TestClientMultipleUploads452=== PAUSE TestClientMultipleUploads453=== RUN TestClientWithDependencies454=== PAUSE TestClientWithDependencies455=== RUN TestPinProtectsFromGC456=== PAUSE TestPinProtectsFromGC457=== RUN TestResolveDBConnectionString458=== PAUSE TestResolveDBConnectionString459=== RUN TestGCAdvisoryLockBlocksConcurrentRun4602026-09-10 17:38:51.334 UTC [921] ERROR: relation "goose_db_version" does not exist at character 364612026-09-10 17:38:51.334 UTC [921] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC4622026/09/10 17:38:51 OK 20241026095416_initial_model.sql (6.65ms)4632026/09/10 17:38:51 OK 20251210153512_drop_unused_gin_index.sql (973.18µs)4642026/09/10 17:38:51 OK 20251218171726_add_pins.sql (2.44ms)4652026/09/10 17:38:51 OK 20260628120000_add_object_size_and_stats.sql (2.23ms)4662026/09/10 17:38:51 OK 20260905000000_add_claims.sql (1.94ms)4672026/09/10 17:38:51 goose: successfully migrated database to version: 202609050000004682026/09/10 17:38:51 OK 1_commit_pending_closure.sql (1.16ms)4692026/09/10 17:38:51 OK 2_object_stats_trigger.sql (573.92µs)4702026/09/10 17:38:51 goose: up to current file version: 2471--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.12s)472=== RUN TestGCBugBareHashReferences473=== PAUSE TestGCBugBareHashReferences474=== RUN TestGCMetrics475=== PAUSE TestGCMetrics476=== RUN TestGCTaskStore_StartNew477=== PAUSE TestGCTaskStore_StartNew478=== RUN TestGCTaskStore_DeduplicateSameParams479=== PAUSE TestGCTaskStore_DeduplicateSameParams480=== RUN TestGCTaskStore_ConflictDifferentParams481=== PAUSE TestGCTaskStore_ConflictDifferentParams482=== RUN TestGCTaskStore_GetEmpty483=== PAUSE TestGCTaskStore_GetEmpty484=== RUN TestGCTaskStore_GetReturnsLatest485=== PAUSE TestGCTaskStore_GetReturnsLatest486=== RUN TestGCTaskStore_CompletedAllowsNewTask487=== PAUSE TestGCTaskStore_CompletedAllowsNewTask488=== RUN TestGCTaskStore_PhaseUpdates489=== PAUSE TestGCTaskStore_PhaseUpdates490=== RUN TestGCTaskStore_Fail491=== PAUSE TestGCTaskStore_Fail492=== RUN TestGracefulShutdownDrainsInflight493=== PAUSE TestGracefulShutdownDrainsInflight494=== RUN TestService_healthCheckHandler495=== PAUSE TestService_healthCheckHandler496=== RUN TestService_readinessHandler497=== PAUSE TestService_readinessHandler498=== RUN TestGenerateLandingPage499=== PAUSE TestGenerateLandingPage500=== RUN TestCacheConfigHandlerMaxNarSize501=== PAUSE TestCacheConfigHandlerMaxNarSize502=== RUN TestCreatePendingClosureRejectsOversizedNAR503=== PAUSE TestCreatePendingClosureRejectsOversizedNAR504=== RUN TestNARDeduplicationMetadataUploadBug505=== PAUSE TestNARDeduplicationMetadataUploadBug506=== RUN TestMetricsInventory507=== PAUSE TestMetricsInventory508=== RUN TestService_NativeMTLS509=== PAUSE TestService_NativeMTLS510=== RUN TestServerTLSConfig511=== PAUSE TestServerTLSConfig512=== RUN TestMultipartCleanup513=== PAUSE TestMultipartCleanup514=== RUN TestObjectStatsTrigger515=== PAUSE TestObjectStatsTrigger516=== RUN TestOrphanedObjectsGC517=== PAUSE TestOrphanedObjectsGC518=== RUN TestOrphanedObjectsGCStressTest519=== PAUSE TestOrphanedObjectsGCStressTest520=== RUN TestResurrectedObjectNotDeleted521=== PAUSE TestResurrectedObjectNotDeleted522=== RUN TestParseSingleRange523=== PAUSE TestParseSingleRange524=== RUN TestIsValidCachePath525=== PAUSE TestIsValidCachePath526=== RUN TestReadProxyNarinfo527=== PAUSE TestReadProxyNarinfo528=== RUN TestReadProxyNarinfoAlreadyDecompressed529=== PAUSE TestReadProxyNarinfoAlreadyDecompressed530=== RUN TestReadProxyNarStreaming531=== PAUSE TestReadProxyNarStreaming532=== RUN TestReadProxy404533=== PAUSE TestReadProxy404534=== RUN TestReadProxyInvalidPath535=== PAUSE TestReadProxyInvalidPath536=== RUN TestReadProxyHead537=== PAUSE TestReadProxyHead538=== RUN TestReadProxyConditionalGet539=== PAUSE TestReadProxyConditionalGet540=== RUN TestReadProxyRootRedirectsToIndexHTML541=== PAUSE TestReadProxyRootRedirectsToIndexHTML542=== RUN TestReadProxyDisabled543=== PAUSE TestReadProxyDisabled544=== RUN TestReadRedirectNar545=== PAUSE TestReadRedirectNar546=== RUN TestReadRedirectKeepsNarinfoProxied547=== PAUSE TestReadRedirectKeepsNarinfoProxied548=== RUN TestReadProxyRangeRequest549=== PAUSE TestReadProxyRangeRequest550=== RUN TestReadRedirectUsesPublicS3URL551=== PAUSE TestReadRedirectUsesPublicS3URL552=== RUN TestRedundantMultipartUpload553=== PAUSE TestRedundantMultipartUpload554=== RUN TestCompleteMultipartUpload_ErrorButObjectExists555=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists556=== RUN TestCompletedNarNotReofferedAcrossClosures557=== PAUSE TestCompletedNarNotReofferedAcrossClosures558=== RUN TestPresignedUploadRegisteredBeforeCommit559=== PAUSE TestPresignedUploadRegisteredBeforeCommit560=== RUN TestService_Rustfstest561=== PAUSE TestService_Rustfstest562=== RUN TestParseSize563=== PAUSE TestParseSize564=== RUN TestSkippedUploadsHandler565=== PAUSE TestSkippedUploadsHandler566=== RUN TestSystemdListenerNotActivated567--- PASS: TestSystemdListenerNotActivated (0.00s)568=== RUN TestWatchdogBeatsWhenHealthy569--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)570=== RUN TestWatchdogSkipsWhenUnhealthy5712026/09/10 17:38:51 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5722026/09/10 17:38:51 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5732026/09/10 17:38:51 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5742026/09/10 17:38:51 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5752026/09/10 17:38:51 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5762026/09/10 17:38:51 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5772026/09/10 17:38:51 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5782026/09/10 17:38:51 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5792026/09/10 17:38:51 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5802026/09/10 17:38:51 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"581--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)582=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle583=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle584=== RUN TestProxyWriteTimeout585=== PAUSE TestProxyWriteTimeout586=== RUN TestIsValidUploadKey587=== PAUSE TestIsValidUploadKey588=== RUN TestUploadHandlersRejectInvalidKeys589=== PAUSE TestUploadHandlersRejectInvalidKeys590=== RUN TestUploadHandlersRejectOversizedBody591=== PAUSE TestUploadHandlersRejectOversizedBody592=== RUN TestService_cleanupPendingClosuresHandler593=== PAUSE TestService_cleanupPendingClosuresHandler594=== RUN TestService_createPendingClosureHandler595=== PAUSE TestService_createPendingClosureHandler596=== RUN TestService_verifyS3Integrity597=== PAUSE TestService_verifyS3Integrity598=== RUN TestCompleteMultipartUnregistered599=== PAUSE TestCompleteMultipartUnregistered600=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT601=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT602=== CONT TestService_AuthMiddleware603=== CONT TestCompleteMultipartUnregistered604=== CONT TestCreatePendingClosureRejectsOversizedNAR605=== CONT TestClientIntegration606=== CONT TestService_ReadScope_PublicByDefault607=== CONT TestService_ReadAuthMiddleware608=== CONT TestClaim_TooManyStreams609=== CONT TestClientErrorHandling6102026/09/10 17:38:51 INFO Received uploads request method=POST path=/api/pending_closures611=== RUN TestClientErrorHandling/InvalidStorePath612=== CONT TestClientCADerivations613=== CONT TestClaim_StreamsThroughServer614=== CONT TestClaim_InputsTouched615=== CONT TestClaim_TwoInstances616=== CONT TestClaim_StaleHeartbeatStolen617=== CONT TestClaim_FailWithoutKindReleases618=== CONT TestClaim_FailWakesWaitersButIsNotRemembered619=== CONT TestClaim_HolderDisconnectKeepsClaim620=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT621=== CONT TestClaim_BuildWaitComplete622=== CONT TestClaim_GCMarkedOutputCountsAsAbsent623=== CONT TestService_AuthMiddleware_MTLSBoundSubjects624=== CONT TestReadProxyDisabled625=== CONT TestService_verifyS3Integrity626=== CONT TestService_createPendingClosureHandler627=== CONT TestGCTaskStore_GetEmpty628=== CONT TestUploadHandlersRejectOversizedBody629=== PAUSE TestClientErrorHandling/InvalidStorePath630--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)631=== CONT TestService_cleanupPendingClosuresHandler632=== RUN TestClientErrorHandling/InvalidAuthToken633=== PAUSE TestClientErrorHandling/InvalidAuthToken634=== RUN TestClientErrorHandling/ServerNotAvailable635=== PAUSE TestClientErrorHandling/ServerNotAvailable636--- PASS: TestGCTaskStore_GetEmpty (0.00s)637=== CONT TestUploadHandlersRejectInvalidKeys638=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info639=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info640=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal641=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal642=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key643=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key644=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key645=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key646=== CONT TestIsValidUploadKey647=== RUN TestIsValidUploadKey/narinfo648=== PAUSE TestIsValidUploadKey/narinfo649=== RUN TestIsValidUploadKey/nar_zst650=== PAUSE TestIsValidUploadKey/nar_zst651=== RUN TestIsValidUploadKey/nar_xz652=== PAUSE TestIsValidUploadKey/nar_xz653=== RUN TestIsValidUploadKey/nar_plain654=== PAUSE TestIsValidUploadKey/nar_plain655=== RUN TestIsValidUploadKey/listing656=== PAUSE TestIsValidUploadKey/listing657=== RUN TestIsValidUploadKey/build_log658=== PAUSE TestIsValidUploadKey/build_log659=== RUN TestIsValidUploadKey/build_log_home-manager_file660=== PAUSE TestIsValidUploadKey/build_log_home-manager_file661=== RUN TestIsValidUploadKey/build_log_plus_in_name662=== PAUSE TestIsValidUploadKey/build_log_plus_in_name663=== RUN TestIsValidUploadKey/build_log_question_mark664=== PAUSE TestIsValidUploadKey/build_log_question_mark665=== RUN TestIsValidUploadKey/build_log_equals666=== PAUSE TestIsValidUploadKey/build_log_equals667=== RUN TestIsValidUploadKey/realisation668=== PAUSE TestIsValidUploadKey/realisation669=== RUN TestIsValidUploadKey/realisation_plus_in_output670=== PAUSE TestIsValidUploadKey/realisation_plus_in_output671=== RUN TestIsValidUploadKey/nix-cache-info672=== PAUSE TestIsValidUploadKey/nix-cache-info673=== RUN TestIsValidUploadKey/index.html674=== PAUSE TestIsValidUploadKey/index.html675=== RUN TestIsValidUploadKey/narinfo_key,_nar_type676=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type677=== RUN TestIsValidUploadKey/nar_key,_narinfo_type678=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type679=== RUN TestIsValidUploadKey/listing_key,_narinfo_type680=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type681=== RUN TestIsValidUploadKey/traversal682=== PAUSE TestIsValidUploadKey/traversal683=== RUN TestIsValidUploadKey/traversal_nar684=== PAUSE TestIsValidUploadKey/traversal_nar685=== RUN TestIsValidUploadKey/absolute686=== PAUSE TestIsValidUploadKey/absolute687=== RUN TestIsValidUploadKey/empty_key688=== PAUSE TestIsValidUploadKey/empty_key689=== RUN TestIsValidUploadKey/unknown_type690=== PAUSE TestIsValidUploadKey/unknown_type691=== CONT TestCacheConfigHandlerMaxNarSize692--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)693=== CONT TestProxyWriteTimeout694=== RUN TestProxyWriteTimeout/narinfo695=== PAUSE TestProxyWriteTimeout/narinfo696=== RUN TestProxyWriteTimeout/1_GiB_nar697=== PAUSE TestProxyWriteTimeout/1_GiB_nar698=== RUN TestProxyWriteTimeout/10_GiB_nar699=== PAUSE TestProxyWriteTimeout/10_GiB_nar700=== RUN TestProxyWriteTimeout/unknown_size701=== PAUSE TestProxyWriteTimeout/unknown_size702=== CONT TestGenerateLandingPage703--- PASS: TestGenerateLandingPage (0.01s)704=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle7052026-09-10 17:38:51.722 UTC [993] ERROR: relation "goose_db_version" does not exist at character 367062026-09-10 17:38:51.722 UTC [993] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7072026-09-10 17:38:51.723 UTC [994] ERROR: relation "goose_db_version" does not exist at character 367082026-09-10 17:38:51.723 UTC [994] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7092026-09-10 17:38:51.726 UTC [997] ERROR: relation "goose_db_version" does not exist at character 367102026-09-10 17:38:51.726 UTC [997] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7112026-09-10 17:38:51.727 UTC [998] ERROR: relation "goose_db_version" does not exist at character 367122026-09-10 17:38:51.727 UTC [998] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7132026-09-10 17:38:51.728 UTC [999] ERROR: relation "goose_db_version" does not exist at character 367142026-09-10 17:38:51.728 UTC [999] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC715=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts716=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts717=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure718=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure719=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart720=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart721=== CONT TestService_readinessHandler7222026-09-10 17:38:51.816 UTC [1002] ERROR: relation "goose_db_version" does not exist at character 367232026-09-10 17:38:51.816 UTC [1002] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7242026-09-10 17:38:51.817 UTC [1003] ERROR: relation "goose_db_version" does not exist at character 367252026-09-10 17:38:51.817 UTC [1003] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7262026/09/10 17:38:51 OK 20241026095416_initial_model.sql (67.74ms)7272026/09/10 17:38:51 OK 20241026095416_initial_model.sql (74.26ms)7282026/09/10 17:38:51 OK 20251210153512_drop_unused_gin_index.sql (4.11ms)7292026/09/10 17:38:51 OK 20251210153512_drop_unused_gin_index.sql (3.69ms)7302026/09/10 17:38:51 OK 20251218171726_add_pins.sql (14.56ms)7312026/09/10 17:38:51 OK 20251218171726_add_pins.sql (16.51ms)7322026/09/10 17:38:51 OK 20260628120000_add_object_size_and_stats.sql (8.63ms)7332026/09/10 17:38:51 OK 20241026095416_initial_model.sql (15.68ms)7342026/09/10 17:38:51 OK 20260628120000_add_object_size_and_stats.sql (9.56ms)7352026/09/10 17:38:51 OK 20241026095416_initial_model.sql (15.31ms)7362026/09/10 17:38:51 OK 20251210153512_drop_unused_gin_index.sql (2.38ms)7372026/09/10 17:38:51 OK 20241026095416_initial_model.sql (38.95ms)7382026/09/10 17:38:51 OK 20241026095416_initial_model.sql (43.91ms)7392026/09/10 17:38:51 OK 20241026095416_initial_model.sql (41.57ms)7402026/09/10 17:38:51 OK 20251210153512_drop_unused_gin_index.sql (3.21ms)7412026/09/10 17:38:51 OK 20260905000000_add_claims.sql (8.82ms)7422026/09/10 17:38:51 goose: successfully migrated database to version: 202609050000007432026/09/10 17:38:51 OK 20251210153512_drop_unused_gin_index.sql (5.38ms)7442026/09/10 17:38:51 OK 20251210153512_drop_unused_gin_index.sql (5.31ms)7452026/09/10 17:38:51 OK 20251210153512_drop_unused_gin_index.sql (5.28ms)7462026/09/10 17:38:51 OK 1_commit_pending_closure.sql (4.49ms)7472026-09-10 17:38:51.861 UTC [1005] ERROR: relation "goose_db_version" does not exist at character 367482026-09-10 17:38:51.861 UTC [1005] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7492026/09/10 17:38:51 OK 20251218171726_add_pins.sql (17.38ms)7502026/09/10 17:38:51 OK 20251218171726_add_pins.sql (16.72ms)7512026/09/10 17:38:51 OK 20260905000000_add_claims.sql (21.08ms)7522026/09/10 17:38:51 OK 2_object_stats_trigger.sql (10.62ms)7532026/09/10 17:38:51 goose: up to current file version: 27542026/09/10 17:38:51 goose: successfully migrated database to version: 202609050000007552026/09/10 17:38:51 OK 1_commit_pending_closure.sql (5.97ms)7562026/09/10 17:38:51 OK 20260628120000_add_object_size_and_stats.sql (8.14ms)7572026/09/10 17:38:51 OK 20251218171726_add_pins.sql (21.02ms)7582026/09/10 17:38:51 OK 20251218171726_add_pins.sql (20.91ms)7592026/09/10 17:38:51 OK 20260628120000_add_object_size_and_stats.sql (10.64ms)7602026/09/10 17:38:51 OK 20251218171726_add_pins.sql (21.11ms)7612026/09/10 17:38:51 OK 2_object_stats_trigger.sql (3.41ms)7622026/09/10 17:38:51 goose: up to current file version: 27632026/09/10 17:38:51 OK 20260905000000_add_claims.sql (5.38ms)7642026/09/10 17:38:51 goose: successfully migrated database to version: 202609050000007652026/09/10 17:38:51 OK 20260628120000_add_object_size_and_stats.sql (5.48ms)7662026/09/10 17:38:51 OK 20260905000000_add_claims.sql (6.61ms)7672026/09/10 17:38:51 goose: successfully migrated database to version: 202609050000007682026/09/10 17:38:51 OK 20260628120000_add_object_size_and_stats.sql (7.79ms)7692026/09/10 17:38:51 OK 1_commit_pending_closure.sql (3.12ms)7702026/09/10 17:38:51 OK 20260628120000_add_object_size_and_stats.sql (8.57ms)7712026/09/10 17:38:51 OK 20260905000000_add_claims.sql (4.38ms)7722026/09/10 17:38:51 goose: successfully migrated database to version: 202609050000007732026/09/10 17:38:51 OK 1_commit_pending_closure.sql (3.38ms)7742026/09/10 17:38:51 OK 2_object_stats_trigger.sql (2.51ms)7752026/09/10 17:38:51 goose: up to current file version: 27762026/09/10 17:38:51 OK 2_object_stats_trigger.sql (2.11ms)7772026/09/10 17:38:51 goose: up to current file version: 27782026-09-10 17:38:51.892 UTC [1006] ERROR: relation "goose_db_version" does not exist at character 367792026-09-10 17:38:51.892 UTC [1006] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7802026/09/10 17:38:51 OK 1_commit_pending_closure.sql (3.46ms)7812026-09-10 17:38:51.893 UTC [1007] ERROR: relation "goose_db_version" does not exist at character 367822026-09-10 17:38:51.893 UTC [1007] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7832026/09/10 17:38:51 OK 20260905000000_add_claims.sql (7.5ms)7842026/09/10 17:38:51 goose: successfully migrated database to version: 202609050000007852026/09/10 17:38:51 OK 20260905000000_add_claims.sql (8.1ms)7862026/09/10 17:38:51 goose: successfully migrated database to version: 202609050000007872026/09/10 17:38:51 OK 20241026095416_initial_model.sql (15.73ms)7882026/09/10 17:38:51 OK 2_object_stats_trigger.sql (4.83ms)7892026/09/10 17:38:51 goose: up to current file version: 27902026/09/10 17:38:51 INFO Received complete multipart upload request method=POST path=/api/multipart/complete7912026-09-10 17:38:51.899 UTC [1008] ERROR: relation "goose_db_version" does not exist at character 367922026-09-10 17:38:51.899 UTC [1008] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7932026/09/10 17:38:51 OK 1_commit_pending_closure.sql (4.64ms)7942026/09/10 17:38:51 OK 1_commit_pending_closure.sql (4.46ms)7952026/09/10 17:38:51 OK 20251210153512_drop_unused_gin_index.sql (4.11ms)7962026-09-10 17:38:51.901 UTC [1010] ERROR: relation "goose_db_version" does not exist at character 367972026-09-10 17:38:51.901 UTC [1010] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7982026/09/10 17:38:51 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst7992026-09-10 17:38:51.902 UTC [1011] ERROR: relation "goose_db_version" does not exist at character 368002026-09-10 17:38:51.902 UTC [1011] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC801--- PASS: TestCompleteMultipartUnregistered (0.29s)802=== CONT TestSkippedUploadsHandler8032026-09-10 17:38:51.902 UTC [1012] ERROR: relation "goose_db_version" does not exist at character 368042026-09-10 17:38:51.902 UTC [1012] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8052026-09-10 17:38:51.903 UTC [1009] ERROR: relation "goose_db_version" does not exist at character 368062026-09-10 17:38:51.903 UTC [1009] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8072026/09/10 17:38:51 INFO Client skipped oversized paths paths=3 nar_bytes=50000000008082026/09/10 17:38:51 OK 2_object_stats_trigger.sql (4.32ms)8092026/09/10 17:38:51 goose: up to current file version: 2810--- PASS: TestSkippedUploadsHandler (0.00s)811=== CONT TestService_healthCheckHandler8122026-09-10 17:38:51.908 UTC [1013] ERROR: relation "goose_db_version" does not exist at character 368132026-09-10 17:38:51.908 UTC [1013] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8142026/09/10 17:38:51 OK 2_object_stats_trigger.sql (12.56ms)8152026/09/10 17:38:51 goose: up to current file version: 28162026/09/10 17:38:51 OK 20251218171726_add_pins.sql (15.38ms)8172026/09/10 17:38:51 OK 20241026095416_initial_model.sql (13.66ms)8182026/09/10 17:38:51 OK 20241026095416_initial_model.sql (14.64ms)8192026/09/10 17:38:51 OK 20251210153512_drop_unused_gin_index.sql (2.21ms)8202026/09/10 17:38:51 OK 20251210153512_drop_unused_gin_index.sql (2.1ms)8212026/09/10 17:38:51 OK 20260628120000_add_object_size_and_stats.sql (4.55ms)8222026/09/10 17:38:51 OK 20251218171726_add_pins.sql (3.27ms)8232026/09/10 17:38:51 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"824--- PASS: TestService_AuthMiddleware (0.31s)825=== CONT TestParseSize826--- PASS: TestParseSize (0.00s)827=== CONT TestService_Rustfstest8282026/09/10 17:38:51 OK 20260905000000_add_claims.sql (3.55ms)8292026/09/10 17:38:51 goose: successfully migrated database to version: 202609050000008302026/09/10 17:38:51 OK 20251218171726_add_pins.sql (4.26ms)8312026/09/10 17:38:51 OK 20260628120000_add_object_size_and_stats.sql (3.25ms)8322026-09-10 17:38:51.928 UTC [1017] ERROR: relation "goose_db_version" does not exist at character 368332026-09-10 17:38:51.928 UTC [1017] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8342026/09/10 17:38:51 OK 1_commit_pending_closure.sql (3.5ms)8352026/09/10 17:38:51 OK 20241026095416_initial_model.sql (10.6ms)8362026-09-10 17:38:51.929 UTC [1018] ERROR: relation "goose_db_version" does not exist at character 368372026-09-10 17:38:51.929 UTC [1018] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8382026/09/10 17:38:51 OK 20241026095416_initial_model.sql (12.22ms)8392026/09/10 17:38:51 OK 20241026095416_initial_model.sql (12.02ms)8402026/09/10 17:38:51 OK 20241026095416_initial_model.sql (11.98ms)8412026/09/10 17:38:51 OK 20260905000000_add_claims.sql (3.78ms)8422026/09/10 17:38:51 goose: successfully migrated database to version: 202609050000008432026-09-10 17:38:51.930 UTC [1020] ERROR: relation "goose_db_version" does not exist at character 368442026-09-10 17:38:51.930 UTC [1020] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8452026-09-10 17:38:51.930 UTC [1019] ERROR: relation "goose_db_version" does not exist at character 368462026-09-10 17:38:51.930 UTC [1019] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8472026-09-10 17:38:51.930 UTC [1021] ERROR: relation "goose_db_version" does not exist at character 368482026-09-10 17:38:51.930 UTC [1021] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8492026/09/10 17:38:51 OK 20241026095416_initial_model.sql (12.91ms)8502026/09/10 17:38:51 OK 2_object_stats_trigger.sql (2.48ms)8512026/09/10 17:38:51 goose: up to current file version: 28522026/09/10 17:38:51 OK 20241026095416_initial_model.sql (12.35ms)8532026/09/10 17:38:51 OK 20251210153512_drop_unused_gin_index.sql (2.18ms)8542026/09/10 17:38:51 OK 20260628120000_add_object_size_and_stats.sql (6.08ms)8552026-09-10 17:38:51.931 UTC [1016] ERROR: relation "goose_db_version" does not exist at character 368562026-09-10 17:38:51.931 UTC [1016] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8572026/09/10 17:38:51 OK 20251210153512_drop_unused_gin_index.sql (1.47ms)8582026/09/10 17:38:51 OK 20251210153512_drop_unused_gin_index.sql (1.79ms)8592026/09/10 17:38:51 OK 20251210153512_drop_unused_gin_index.sql (1.37ms)8602026/09/10 17:38:51 OK 20251210153512_drop_unused_gin_index.sql (2.1ms)8612026/09/10 17:38:51 OK 1_commit_pending_closure.sql (2.34ms)8622026/09/10 17:38:51 OK 20251210153512_drop_unused_gin_index.sql (1.57ms)8632026/09/10 17:38:51 OK 20260905000000_add_claims.sql (3.63ms)8642026/09/10 17:38:51 goose: successfully migrated database to version: 202609050000008652026/09/10 17:38:51 OK 2_object_stats_trigger.sql (2.21ms)8662026/09/10 17:38:51 goose: up to current file version: 28672026-09-10 17:38:51.935 UTC [1023] ERROR: relation "goose_db_version" does not exist at character 368682026-09-10 17:38:51.935 UTC [1023] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8692026/09/10 17:38:51 OK 20251218171726_add_pins.sql (5.51ms)8702026/09/10 17:38:51 OK 20251218171726_add_pins.sql (4.5ms)8712026/09/10 17:38:51 OK 20251218171726_add_pins.sql (4.52ms)8722026/09/10 17:38:51 OK 20251218171726_add_pins.sql (5.2ms)8732026/09/10 17:38:51 OK 20251218171726_add_pins.sql (4.83ms)8742026-09-10 17:38:51.937 UTC [1025] ERROR: relation "goose_db_version" does not exist at character 368752026-09-10 17:38:51.937 UTC [1025] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8762026/09/10 17:38:51 OK 1_commit_pending_closure.sql (2.55ms)8772026/09/10 17:38:51 OK 20251218171726_add_pins.sql (4.71ms)8782026/09/10 17:38:51 OK 2_object_stats_trigger.sql (1.72ms)8792026/09/10 17:38:51 goose: up to current file version: 28802026/09/10 17:38:51 OK 20260628120000_add_object_size_and_stats.sql (4.51ms)8812026/09/10 17:38:51 OK 20260628120000_add_object_size_and_stats.sql (5.09ms)8822026/09/10 17:38:51 OK 20260628120000_add_object_size_and_stats.sql (4.41ms)8832026/09/10 17:38:51 OK 20260628120000_add_object_size_and_stats.sql (5.2ms)8842026/09/10 17:38:51 OK 20260628120000_add_object_size_and_stats.sql (5.19ms)8852026/09/10 17:38:51 OK 20260628120000_add_object_size_and_stats.sql (5.99ms)8862026/09/10 17:38:51 OK 20260905000000_add_claims.sql (3.56ms)8872026/09/10 17:38:51 goose: successfully migrated database to version: 202609050000008882026/09/10 17:38:51 OK 20260905000000_add_claims.sql (4.29ms)8892026/09/10 17:38:51 goose: successfully migrated database to version: 202609050000008902026/09/10 17:38:51 OK 20260905000000_add_claims.sql (4.56ms)8912026/09/10 17:38:51 OK 20260905000000_add_claims.sql (4.68ms)8922026/09/10 17:38:51 goose: successfully migrated database to version: 202609050000008932026/09/10 17:38:51 OK 20241026095416_initial_model.sql (12.25ms)8942026/09/10 17:38:51 goose: successfully migrated database to version: 202609050000008952026/09/10 17:38:51 OK 20260905000000_add_claims.sql (4.66ms)8962026/09/10 17:38:51 goose: successfully migrated database to version: 202609050000008972026/09/10 17:38:51 OK 20241026095416_initial_model.sql (12.74ms)8982026/09/10 17:38:51 OK 20260905000000_add_claims.sql (5.14ms)8992026/09/10 17:38:51 goose: successfully migrated database to version: 20260905000000900--- PASS: TestService_ReadScope_PublicByDefault (0.34s)901=== CONT TestGracefulShutdownDrainsInflight9022026/09/10 17:38:51 INFO Starting HTTP server address=127.0.0.1:463439032026/09/10 17:38:51 INFO Shutdown signal received, draining in-flight requests timeout=10s9042026/09/10 17:38:51 OK 1_commit_pending_closure.sql (3.61ms)9052026/09/10 17:38:51 OK 1_commit_pending_closure.sql (3.59ms)9062026/09/10 17:38:51 OK 1_commit_pending_closure.sql (2.39ms)9072026/09/10 17:38:51 OK 20241026095416_initial_model.sql (11.81ms)9082026/09/10 17:38:51 OK 20241026095416_initial_model.sql (11.82ms)9092026/09/10 17:38:51 OK 20251210153512_drop_unused_gin_index.sql (2.25ms)9102026/09/10 17:38:51 OK 1_commit_pending_closure.sql (3.2ms)9112026/09/10 17:38:51 OK 20241026095416_initial_model.sql (11.36ms)9122026/09/10 17:38:51 OK 1_commit_pending_closure.sql (3.31ms)9132026/09/10 17:38:51 OK 20241026095416_initial_model.sql (12.43ms)9142026/09/10 17:38:51 OK 20251210153512_drop_unused_gin_index.sql (2.97ms)9152026/09/10 17:38:51 OK 1_commit_pending_closure.sql (3.04ms)9162026/09/10 17:38:51 OK 20251210153512_drop_unused_gin_index.sql (1.86ms)9172026/09/10 17:38:51 OK 20251210153512_drop_unused_gin_index.sql (1.84ms)9182026/09/10 17:38:51 OK 2_object_stats_trigger.sql (1.98ms)9192026/09/10 17:38:51 goose: up to current file version: 29202026/09/10 17:38:51 OK 2_object_stats_trigger.sql (1.85ms)9212026/09/10 17:38:51 goose: up to current file version: 29222026/09/10 17:38:51 OK 2_object_stats_trigger.sql (2.01ms)9232026/09/10 17:38:51 goose: up to current file version: 29242026/09/10 17:38:51 OK 2_object_stats_trigger.sql (2.02ms)9252026/09/10 17:38:51 goose: up to current file version: 29262026/09/10 17:38:51 OK 2_object_stats_trigger.sql (2.81ms)9272026/09/10 17:38:51 goose: up to current file version: 29282026/09/10 17:38:51 OK 20251210153512_drop_unused_gin_index.sql (2.12ms)9292026/09/10 17:38:51 OK 2_object_stats_trigger.sql (1.85ms)9302026/09/10 17:38:51 goose: up to current file version: 29312026/09/10 17:38:51 OK 20251210153512_drop_unused_gin_index.sql (3ms)9322026/09/10 17:38:51 OK 20241026095416_initial_model.sql (10.71ms)9332026/09/10 17:38:51 OK 20251218171726_add_pins.sql (3.41ms)9342026/09/10 17:38:51 OK 20251218171726_add_pins.sql (4.26ms)9352026/09/10 17:38:51 OK 20251218171726_add_pins.sql (3.17ms)9362026/09/10 17:38:51 OK 20241026095416_initial_model.sql (9.63ms)9372026/09/10 17:38:51 OK 20251218171726_add_pins.sql (4.33ms)9382026/09/10 17:38:51 OK 20251210153512_drop_unused_gin_index.sql (2.47ms)9392026/09/10 17:38:51 OK 20251218171726_add_pins.sql (4.08ms)9402026/09/10 17:38:51 OK 20251210153512_drop_unused_gin_index.sql (1.97ms)9412026/09/10 17:38:51 OK 20251218171726_add_pins.sql (3.99ms)9422026/09/10 17:38:51 OK 20260628120000_add_object_size_and_stats.sql (3.52ms)9432026/09/10 17:38:51 OK 20260628120000_add_object_size_and_stats.sql (3.62ms)9442026/09/10 17:38:51 OK 20260628120000_add_object_size_and_stats.sql (4.4ms)9452026/09/10 17:38:51 OK 20251218171726_add_pins.sql (3.11ms)9462026/09/10 17:38:51 OK 20251218171726_add_pins.sql (3.01ms)9472026/09/10 17:38:51 OK 20260628120000_add_object_size_and_stats.sql (3.96ms)9482026/09/10 17:38:51 OK 20260628120000_add_object_size_and_stats.sql (2.97ms)9492026/09/10 17:38:51 OK 20260628120000_add_object_size_and_stats.sql (3.82ms)9502026/09/10 17:38:51 OK 20260905000000_add_claims.sql (2.95ms)9512026/09/10 17:38:51 goose: successfully migrated database to version: 202609050000009522026/09/10 17:38:51 OK 20260905000000_add_claims.sql (2.76ms)9532026/09/10 17:38:51 goose: successfully migrated database to version: 202609050000009542026/09/10 17:38:51 OK 20260905000000_add_claims.sql (3.41ms)9552026/09/10 17:38:51 goose: successfully migrated database to version: 202609050000009562026/09/10 17:38:51 OK 20260628120000_add_object_size_and_stats.sql (2.74ms)9572026/09/10 17:38:51 OK 1_commit_pending_closure.sql (1.95ms)9582026/09/10 17:38:51 OK 20260905000000_add_claims.sql (2.78ms)9592026/09/10 17:38:51 goose: successfully migrated database to version: 202609050000009602026/09/10 17:38:51 OK 20260905000000_add_claims.sql (2.9ms)9612026/09/10 17:38:51 OK 20260628120000_add_object_size_and_stats.sql (3.55ms)9622026/09/10 17:38:51 goose: successfully migrated database to version: 202609050000009632026/09/10 17:38:51 OK 1_commit_pending_closure.sql (2.17ms)9642026/09/10 17:38:51 OK 1_commit_pending_closure.sql (2.21ms)9652026/09/10 17:38:51 OK 20260905000000_add_claims.sql (3.72ms)9662026/09/10 17:38:51 goose: successfully migrated database to version: 202609050000009672026/09/10 17:38:51 OK 2_object_stats_trigger.sql (1.51ms)9682026/09/10 17:38:51 goose: up to current file version: 29692026/09/10 17:38:51 OK 1_commit_pending_closure.sql (2.25ms)9702026/09/10 17:38:51 OK 2_object_stats_trigger.sql (2.35ms)9712026/09/10 17:38:51 goose: up to current file version: 29722026/09/10 17:38:51 OK 20260905000000_add_claims.sql (3.98ms)9732026/09/10 17:38:51 goose: successfully migrated database to version: 202609050000009742026/09/10 17:38:51 OK 2_object_stats_trigger.sql (1.73ms)9752026/09/10 17:38:51 goose: up to current file version: 29762026/09/10 17:38:51 OK 1_commit_pending_closure.sql (2.4ms)9772026/09/10 17:38:51 OK 20260905000000_add_claims.sql (3.01ms)9782026/09/10 17:38:51 goose: successfully migrated database to version: 202609050000009792026/09/10 17:38:51 OK 1_commit_pending_closure.sql (2.22ms)9802026/09/10 17:38:51 OK 2_object_stats_trigger.sql (1.43ms)9812026/09/10 17:38:51 goose: up to current file version: 29822026/09/10 17:38:51 OK 2_object_stats_trigger.sql (1.06ms)9832026/09/10 17:38:51 goose: up to current file version: 29842026/09/10 17:38:51 OK 1_commit_pending_closure.sql (1.89ms)9852026/09/10 17:38:51 OK 2_object_stats_trigger.sql (1.33ms)9862026/09/10 17:38:51 goose: up to current file version: 29872026/09/10 17:38:51 OK 1_commit_pending_closure.sql (2.27ms)9882026/09/10 17:38:51 OK 2_object_stats_trigger.sql (1.65ms)9892026/09/10 17:38:51 goose: up to current file version: 29902026/09/10 17:38:51 OK 2_object_stats_trigger.sql (1.22ms)9912026/09/10 17:38:51 goose: up to current file version: 29922026/09/10 17:38:51 WARN claim: cannot clear write deadline error="feature not supported"9932026/09/10 17:38:51 WARN claim: cannot clear write deadline error="feature not supported"9942026/09/10 17:38:51 WARN claim: cannot clear write deadline error="feature not supported"9952026/09/10 17:38:51 INFO Received uploads request method=POST path=/api/pending_closures9962026-09-10 17:38:51.986 UTC [1027] ERROR: relation "goose_db_version" does not exist at character 369972026-09-10 17:38:51.986 UTC [1027] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9982026/09/10 17:38:51 OK 20241026095416_initial_model.sql (6.54ms)9992026/09/10 17:38:51 OK 20251210153512_drop_unused_gin_index.sql (1.11ms)10002026-09-10 17:38:51.999 UTC [1028] ERROR: relation "goose_db_version" does not exist at character 3610012026-09-10 17:38:51.999 UTC [1028] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10022026/09/10 17:38:52 OK 20251218171726_add_pins.sql (1.93ms)10032026/09/10 17:38:52 OK 20260628120000_add_object_size_and_stats.sql (2.3ms)10042026/09/10 17:38:52 OK 20260905000000_add_claims.sql (2.53ms)10052026/09/10 17:38:52 goose: successfully migrated database to version: 2026090500000010062026/09/10 17:38:52 OK 1_commit_pending_closure.sql (1.92ms)10072026/09/10 17:38:52 OK 2_object_stats_trigger.sql (772.08µs)10082026/09/10 17:38:52 goose: up to current file version: 210092026/09/10 17:38:52 OK 20241026095416_initial_model.sql (6.1ms)10102026/09/10 17:38:52 OK 20251210153512_drop_unused_gin_index.sql (769.85µs)10112026/09/10 17:38:52 OK 20251218171726_add_pins.sql (1.72ms)10122026/09/10 17:38:52 OK 20260628120000_add_object_size_and_stats.sql (1.88ms)10132026/09/10 17:38:52 OK 20260905000000_add_claims.sql (1.75ms)10142026/09/10 17:38:52 goose: successfully migrated database to version: 202609050000001015--- PASS: TestGracefulShutdownDrainsInflight (0.07s)1016=== CONT TestPresignedUploadRegisteredBeforeCommit10172026/09/10 17:38:52 OK 1_commit_pending_closure.sql (1.04ms)10182026/09/10 17:38:52 OK 2_object_stats_trigger.sql (432.98µs)10192026/09/10 17:38:52 goose: up to current file version: 21020--- PASS: TestService_ReadAuthMiddleware (0.41s)1021=== CONT TestGCTaskStore_Fail1022--- PASS: TestGCTaskStore_Fail (0.00s)1023=== CONT TestCompletedNarNotReofferedAcrossClosures1024=== NAME TestClientIntegration1025 client_integration_test.go:277: Created store path: /build/TestClientIntegration958883767/002/store/yj2rnp3xys8qppnl5c4mm29b9g8pcikx-test-file.txt10262026/09/10 17:38:52 WARN claim: cannot clear write deadline error="feature not supported"1027--- PASS: TestClaim_TooManyStreams (0.45s)1028=== CONT TestGCTaskStore_PhaseUpdates1029--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)1030=== CONT TestCompleteMultipartUpload_ErrorButObjectExists10312026/09/10 17:38:52 WARN claim: cannot clear write deadline error="feature not supported"10322026/09/10 17:38:52 WARN claim: cannot clear write deadline error="feature not supported"1033--- PASS: TestClaim_FailWithoutKindReleases (0.47s)1034=== CONT TestGCTaskStore_CompletedAllowsNewTask1035--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)1036=== CONT TestRedundantMultipartUpload10372026/09/10 17:38:52 INFO Received uploads request method=POST path=/api/pending_closures10382026/09/10 17:38:52 INFO Received uploads request method=POST path=/api/pending_closures10392026/09/10 17:38:52 INFO Received uploads request method=POST path=/api/pending_closures10402026-09-10 17:38:52.089 UTC [1073] ERROR: relation "goose_db_version" does not exist at character 3610412026-09-10 17:38:52.089 UTC [1073] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10422026-09-10 17:38:52.090 UTC [1075] ERROR: relation "goose_db_version" does not exist at character 3610432026-09-10 17:38:52.090 UTC [1075] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10442026/09/10 17:38:52 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"10452026/09/10 17:38:52 OK 20241026095416_initial_model.sql (8.86ms)10462026/09/10 17:38:52 OK 20241026095416_initial_model.sql (9.2ms)10472026/09/10 17:38:52 OK 20251210153512_drop_unused_gin_index.sql (1.54ms)10482026/09/10 17:38:52 OK 20251210153512_drop_unused_gin_index.sql (1.84ms)10492026/09/10 17:38:52 OK 20251218171726_add_pins.sql (3.89ms)10502026/09/10 17:38:52 WARN claim: cannot clear write deadline error="feature not supported"10512026/09/10 17:38:52 OK 20251218171726_add_pins.sql (3.7ms)10522026/09/10 17:38:52 OK 20260628120000_add_object_size_and_stats.sql (4.5ms)10532026/09/10 17:38:52 OK 20260628120000_add_object_size_and_stats.sql (4.49ms)10542026/09/10 17:38:52 OK 20260905000000_add_claims.sql (2.9ms)10552026/09/10 17:38:52 goose: successfully migrated database to version: 2026090500000010562026/09/10 17:38:52 OK 20260905000000_add_claims.sql (2.93ms)10572026/09/10 17:38:52 goose: successfully migrated database to version: 2026090500000010582026/09/10 17:38:52 OK 1_commit_pending_closure.sql (1.59ms)10592026/09/10 17:38:52 WARN claim: cannot clear write deadline error="feature not supported"1060--- PASS: TestClaim_StaleHeartbeatStolen (0.51s)1061=== CONT TestGCTaskStore_GetReturnsLatest1062--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)1063=== CONT TestReadRedirectUsesPublicS3URL10642026/09/10 17:38:52 OK 1_commit_pending_closure.sql (2.09ms)10652026/09/10 17:38:52 OK 2_object_stats_trigger.sql (1.64ms)10662026/09/10 17:38:52 goose: up to current file version: 210672026/09/10 17:38:52 OK 2_object_stats_trigger.sql (1.29ms)10682026/09/10 17:38:52 goose: up to current file version: 210692026-09-10 17:38:52.126 UTC [1097] ERROR: relation "goose_db_version" does not exist at character 3610702026-09-10 17:38:52.126 UTC [1097] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10712026/09/10 17:38:52 INFO Received uploads request method=POST path=/api/pending_closures1072--- PASS: TestReadProxyDisabled (0.52s)1073=== CONT TestService_AuthMiddleware_MTLSProxyHeader10742026/09/10 17:38:52 OK 20241026095416_initial_model.sql (8.32ms)10752026/09/10 17:38:52 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)10762026/09/10 17:38:52 INFO Uploading yj2rnp3xys8qppnl5c4mm29b9g8pcikx-test-file.txt (152B)10772026/09/10 17:38:52 OK 20251210153512_drop_unused_gin_index.sql (2.03ms)10782026/09/10 17:38:52 OK 20251218171726_add_pins.sql (4.18ms)10792026/09/10 17:38:52 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"10802026/09/10 17:38:52 OK 20260628120000_add_object_size_and_stats.sql (3.28ms)10812026/09/10 17:38:52 WARN Failed to register uploaded object key=yj2rnp3xys8qppnl5c4mm29b9g8pcikx.ls error="server returned 404: 404 page not found\n"10822026/09/10 17:38:52 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign10832026/09/10 17:38:52 INFO Signed narinfos id=1 count=110842026/09/10 17:38:52 INFO Uploading 1 narinfos10852026-09-10 17:38:52.152 UTC [1119] ERROR: relation "goose_db_version" does not exist at character 3610862026-09-10 17:38:52.152 UTC [1119] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10872026/09/10 17:38:52 OK 20260905000000_add_claims.sql (3.84ms)10882026/09/10 17:38:52 goose: successfully migrated database to version: 2026090500000010892026/09/10 17:38:52 INFO Received uploads request method=POST path=/api/pending_closures10902026/09/10 17:38:52 WARN Failed to register uploaded object key=yj2rnp3xys8qppnl5c4mm29b9g8pcikx.narinfo error="server returned 404: 404 page not found\n"10912026/09/10 17:38:52 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete10922026/09/10 17:38:52 OK 1_commit_pending_closure.sql (2.93ms)10932026/09/10 17:38:52 OK 2_object_stats_trigger.sql (1.51ms)10942026/09/10 17:38:52 goose: up to current file version: 210952026/09/10 17:38:52 INFO Completed upload id=110962026/09/10 17:38:52 INFO Upload complete. (98ms)1097=== NAME TestClientIntegration1098 client_integration_test.go:293: Retrieved narinfo from S3:1099 StorePath: /build/TestClientIntegration958883767/002/store/yj2rnp3xys8qppnl5c4mm29b9g8pcikx-test-file.txt1100 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1101 Compression: zstd1102 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11103 NarSize: 1521104 References: 1105 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk111062026/09/10 17:38:52 OK 20241026095416_initial_model.sql (8.72ms)11072026/09/10 17:38:52 OK 20251210153512_drop_unused_gin_index.sql (1.86ms)1108 client_integration_test.go:294: Retrieved .ls file from S3 (compressed size: 77 bytes)1109 client_integration_test.go:294: Decompressed .ls content (64 bytes):1110 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1111 client_integration_test.go:297: Testing garbage collection...1112--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.55s)1113=== CONT TestReadProxyRangeRequest11142026/09/10 17:38:52 OK 20251218171726_add_pins.sql (2.83ms)11152026/09/10 17:38:52 OK 20260628120000_add_object_size_and_stats.sql (2.89ms)11162026/09/10 17:38:52 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"11172026/09/10 17:38:52 WARN mTLS auth: bound subjects configured but subject DN unavailable11182026/09/10 17:38:52 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1119--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (0.56s)1120=== CONT TestService_RequireScope_OIDC11212026/09/10 17:38:52 OK 20260905000000_add_claims.sql (2.86ms)11222026/09/10 17:38:52 goose: successfully migrated database to version: 2026090500000011232026/09/10 17:38:52 OK 1_commit_pending_closure.sql (2.35ms)11242026/09/10 17:38:52 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:43233/oidc11252026/09/10 17:38:52 OK 2_object_stats_trigger.sql (2.27ms)11262026/09/10 17:38:52 goose: up to current file version: 211272026/09/10 17:38:52 WARN claim: cannot clear write deadline error="feature not supported"11282026-09-10 17:38:52.200 UTC [1128] ERROR: relation "goose_db_version" does not exist at character 3611292026-09-10 17:38:52.200 UTC [1128] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11302026/09/10 17:38:52 INFO Starting cleanup of old closures method=DELETE path=/api/closures11312026/09/10 17:38:52 INFO Garbage collection started11322026-09-10 17:38:52.206 UTC [1144] ERROR: relation "goose_db_version" does not exist at character 3611332026-09-10 17:38:52.206 UTC [1144] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11342026/09/10 17:38:52 INFO Aborted multipart uploads count=011352026/09/10 17:38:52 WARN claim: cannot clear write deadline error="feature not supported"11362026/09/10 17:38:52 WARN Force mode enabled - objects will be deleted immediately without grace period11372026/09/10 17:38:52 WARN claim: cannot clear write deadline error="feature not supported"1138--- PASS: TestClaim_FailWakesWaitersButIsNotRemembered (0.60s)1139=== CONT TestReadRedirectKeepsNarinfoProxied11402026/09/10 17:38:52 OK 20241026095416_initial_model.sql (8.95ms)11412026/09/10 17:38:52 OK 20241026095416_initial_model.sql (7.25ms)11422026/09/10 17:38:52 OK 20251210153512_drop_unused_gin_index.sql (2ms)11432026/09/10 17:38:52 WARN claim: cannot clear write deadline error="feature not supported"11442026/09/10 17:38:52 OK 20251210153512_drop_unused_gin_index.sql (2.03ms)11452026/09/10 17:38:52 OK 20251218171726_add_pins.sql (3.59ms)11462026/09/10 17:38:52 OK 20251218171726_add_pins.sql (9.1ms)11472026/09/10 17:38:52 OK 20260628120000_add_object_size_and_stats.sql (9.67ms)11482026/09/10 17:38:52 OK 20260628120000_add_object_size_and_stats.sql (4.55ms)11492026/09/10 17:38:52 WARN claim: cannot clear write deadline error="feature not supported"11502026/09/10 17:38:52 OK 20260905000000_add_claims.sql (3.71ms)11512026/09/10 17:38:52 goose: successfully migrated database to version: 2026090500000011522026/09/10 17:38:52 OK 20260905000000_add_claims.sql (2.98ms)11532026/09/10 17:38:52 goose: successfully migrated database to version: 2026090500000011542026/09/10 17:38:52 OK 1_commit_pending_closure.sql (2.67ms)11552026/09/10 17:38:52 OK 1_commit_pending_closure.sql (2.05ms)11562026/09/10 17:38:52 OK 2_object_stats_trigger.sql (1.89ms)11572026/09/10 17:38:52 goose: up to current file version: 211582026/09/10 17:38:52 OK 2_object_stats_trigger.sql (1.76ms)11592026/09/10 17:38:52 goose: up to current file version: 211602026-09-10 17:38:52.242 UTC [1149] ERROR: relation "goose_db_version" does not exist at character 3611612026-09-10 17:38:52.242 UTC [1149] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11622026/09/10 17:38:52 INFO Received uploads request method=POST path=/api/pending_closures11632026-09-10 17:38:52.253 UTC [1151] ERROR: relation "goose_db_version" does not exist at character 3611642026-09-10 17:38:52.253 UTC [1151] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11652026/09/10 17:38:52 OK 20241026095416_initial_model.sql (8.59ms)11662026/09/10 17:38:52 OK 20251210153512_drop_unused_gin_index.sql (3.75ms)11672026/09/10 17:38:52 OK 20251218171726_add_pins.sql (2.96ms)11682026/09/10 17:38:52 INFO Received uploads request method=POST path=/api/pending_closures11692026/09/10 17:38:52 OK 20260628120000_add_object_size_and_stats.sql (3.02ms)11702026/09/10 17:38:52 OK 20241026095416_initial_model.sql (7.78ms)11712026/09/10 17:38:52 OK 20260905000000_add_claims.sql (3.09ms)11722026/09/10 17:38:52 goose: successfully migrated database to version: 2026090500000011732026/09/10 17:38:52 OK 20251210153512_drop_unused_gin_index.sql (1.28ms)11742026/09/10 17:38:52 OK 1_commit_pending_closure.sql (1.43ms)11752026/09/10 17:38:52 OK 20251218171726_add_pins.sql (1.6ms)11762026/09/10 17:38:52 OK 2_object_stats_trigger.sql (784.72µs)11772026/09/10 17:38:52 goose: up to current file version: 211782026/09/10 17:38:52 OK 20260628120000_add_object_size_and_stats.sql (1.98ms)11792026/09/10 17:38:52 OK 20260905000000_add_claims.sql (1.89ms)11802026/09/10 17:38:52 goose: successfully migrated database to version: 2026090500000011812026/09/10 17:38:52 OK 1_commit_pending_closure.sql (1.43ms)11822026/09/10 17:38:52 OK 2_object_stats_trigger.sql (690.96µs)11832026/09/10 17:38:52 goose: up to current file version: 211842026-09-10 17:38:52.278 UTC [1156] ERROR: relation "goose_db_version" does not exist at character 3611852026-09-10 17:38:52.278 UTC [1156] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11862026/09/10 17:38:52 INFO Received uploads request method=POST path=/api/pending_closures11872026/09/10 17:38:52 OK 20241026095416_initial_model.sql (5.89ms)11882026/09/10 17:38:52 OK 20251210153512_drop_unused_gin_index.sql (845.69µs)11892026/09/10 17:38:52 OK 20251218171726_add_pins.sql (2.61ms)11902026/09/10 17:38:52 OK 20260628120000_add_object_size_and_stats.sql (2.66ms)11912026/09/10 17:38:52 OK 20260905000000_add_claims.sql (3.09ms)11922026/09/10 17:38:52 goose: successfully migrated database to version: 2026090500000011932026/09/10 17:38:52 OK 1_commit_pending_closure.sql (1.49ms)11942026/09/10 17:38:52 OK 2_object_stats_trigger.sql (672.6µs)11952026/09/10 17:38:52 goose: up to current file version: 211962026/09/10 17:38:52 INFO Received cleanup request method=DELETE path=/api/pending_closures11972026/09/10 17:38:52 INFO Aborted multipart uploads count=011982026/09/10 17:38:52 INFO Received uploads request method=POST path=/api/pending_closures11992026/09/10 17:38:52 INFO Received cleanup request method=DELETE path=/api/pending_closures12002026/09/10 17:38:52 INFO Aborted multipart uploads count=112012026/09/10 17:38:52 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete12022026-09-10 17:38:52.336 UTC [1020] ERROR: Closure does not exist: id=112032026-09-10 17:38:52.336 UTC [1020] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 16 at RAISE12042026-09-10 17:38:52.336 UTC [1020] STATEMENT: -- name: CommitPendingClosure :exec1205 SELECT commit_pending_closure($1::bigint)1206 1207--- PASS: TestService_cleanupPendingClosuresHandler (0.72s)1208=== CONT TestReadRedirectNar12092026/09/10 17:38:52 INFO Received uploads request method=POST path=/api/pending_closures12102026/09/10 17:38:52 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12112026/09/10 17:38:52 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12122026/09/10 17:38:52 WARN claim: cannot clear write deadline error="feature not supported"12132026/09/10 17:38:52 INFO Completed multipart upload object_key=nar/0000000000000000000000000000001000000000000000000000.nar.zst upload_id=YzA4YzgyZjMtZjc1OS00ZDlmLWIzZTUtMWIyNzkyMjYzODE5LjBkNzM2YTI3LWJmNTItNDdjNC04ZWJhLTM1NDE4ZGFmYjAyMHgxNzg5MDYxOTMxOTg4OTUxNjkw parts=1012142026/09/10 17:38:52 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign12152026/09/10 17:38:52 INFO Signed narinfos id=1 count=112162026/09/10 17:38:52 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete12172026/09/10 17:38:52 INFO Received uploads request method=POST path=/api/pending_closures12182026/09/10 17:38:52 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign12192026/09/10 17:38:52 INFO Signed narinfos id=2 count=112202026/09/10 17:38:52 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete12212026/09/10 17:38:52 INFO Completed upload id=212222026/09/10 17:38:52 WARN claim: cannot clear write deadline error="feature not supported"12232026/09/10 17:38:52 WARN claim: cannot clear write deadline error="feature not supported"1224--- PASS: TestClaim_BuildWaitComplete (0.78s)1225=== CONT TestGCBugBareHashReferences12262026-09-10 17:38:52.397 UTC [1201] ERROR: relation "goose_db_version" does not exist at character 3612272026-09-10 17:38:52.397 UTC [1201] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12282026/09/10 17:38:52 WARN readiness check failed error="closed pool"1229--- PASS: TestService_readinessHandler (0.59s)1230=== CONT TestGCTaskStore_ConflictDifferentParams1231--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)1232=== CONT TestGCTaskStore_DeduplicateSameParams1233--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)1234=== CONT TestGCTaskStore_StartNew1235--- PASS: TestGCTaskStore_StartNew (0.00s)1236=== CONT TestParseSingleRange1237=== RUN TestParseSingleRange/none1238=== PAUSE TestParseSingleRange/none1239=== RUN TestParseSingleRange/unknown_unit1240=== PAUSE TestParseSingleRange/unknown_unit1241=== RUN TestParseSingleRange/multi-range_ignored1242=== PAUSE TestParseSingleRange/multi-range_ignored1243=== RUN TestParseSingleRange/malformed_no_dash1244=== PAUSE TestParseSingleRange/malformed_no_dash1245=== RUN TestParseSingleRange/malformed_both_empty1246=== PAUSE TestParseSingleRange/malformed_both_empty1247=== RUN TestParseSingleRange/malformed_end_before_start1248=== PAUSE TestParseSingleRange/malformed_end_before_start1249=== RUN TestParseSingleRange/closed1250=== PAUSE TestParseSingleRange/closed1251=== RUN TestParseSingleRange/open-ended1252=== PAUSE TestParseSingleRange/open-ended1253=== RUN TestParseSingleRange/end_clamped_to_size1254=== PAUSE TestParseSingleRange/end_clamped_to_size1255=== RUN TestParseSingleRange/suffix1256=== PAUSE TestParseSingleRange/suffix1257=== RUN TestParseSingleRange/suffix_exceeds_size1258=== PAUSE TestParseSingleRange/suffix_exceeds_size1259=== RUN TestParseSingleRange/single_byte1260=== PAUSE TestParseSingleRange/single_byte1261=== RUN TestParseSingleRange/start_past_EOF1262=== PAUSE TestParseSingleRange/start_past_EOF1263=== RUN TestParseSingleRange/start_far_past_EOF1264=== PAUSE TestParseSingleRange/start_far_past_EOF1265=== CONT TestGCMetrics12662026/09/10 17:38:52 WARN claim: cannot clear write deadline error="feature not supported"12672026/09/10 17:38:52 INFO Received uploads request method=POST path=/api/pending_closures12682026/09/10 17:38:52 OK 20241026095416_initial_model.sql (8.61ms)12692026/09/10 17:38:52 OK 20251210153512_drop_unused_gin_index.sql (1.57ms)12702026/09/10 17:38:52 OK 20251218171726_add_pins.sql (2.99ms)12712026/09/10 17:38:52 OK 20260628120000_add_object_size_and_stats.sql (3.33ms)1272--- PASS: TestService_healthCheckHandler (0.51s)1273=== CONT TestReadProxyRootRedirectsToIndexHTML12742026/09/10 17:38:52 OK 20260905000000_add_claims.sql (3.14ms)12752026/09/10 17:38:52 goose: successfully migrated database to version: 2026090500000012762026/09/10 17:38:52 OK 1_commit_pending_closure.sql (3.09ms)12772026/09/10 17:38:52 OK 2_object_stats_trigger.sql (1.39ms)12782026/09/10 17:38:52 goose: up to current file version: 21279--- PASS: TestService_Rustfstest (0.52s)1280=== CONT TestReadProxyConditionalGet1281=== NAME TestClientCADerivations1282 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations1134066859/001/store/8yr2q0df4gjryblhznirdj1jdg2iwyaa-ca-test12832026/09/10 17:38:52 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12842026/09/10 17:38:52 INFO Received uploads request method=POST path=/api/pending_closures12852026/09/10 17:38:52 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=YzA4YzgyZjMtZjc1OS00ZDlmLWIzZTUtMWIyNzkyMjYzODE5LjA5MWEyZDk0LTZjNTctNDg1ZS1hYzQ2LTc1ZDE1OGVlOWI1NXgxNzg5MDYxOTMyMDk3ODgwODcw parts=1012862026/09/10 17:38:52 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete12872026/09/10 17:38:52 INFO Completed upload id=112882026/09/10 17:38:52 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000012892026/09/10 17:38:52 INFO Received uploads request method=POST path=/api/pending_closures12902026-09-10 17:38:52.470 UTC [1230] ERROR: relation "goose_db_version" does not exist at character 3612912026-09-10 17:38:52.470 UTC [1230] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12922026/09/10 17:38:52 INFO Starting cleanup of old closures method=DELETE path=/api/closures1293 client_ca_test.go:139: Found 1 dependencies (including self)12942026/09/10 17:38:52 INFO Aborted multipart uploads count=012952026/09/10 17:38:52 INFO Received uploads request method=POST path=/api/pending_closures12962026/09/10 17:38:52 OK 20241026095416_initial_model.sql (8.61ms)12972026/09/10 17:38:52 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=012982026/09/10 17:38:52 OK 20251210153512_drop_unused_gin_index.sql (1.46ms)12992026/09/10 17:38:52 INFO Vacuumed table table=pending_closures13002026-09-10 17:38:52.490 UTC [1249] ERROR: relation "goose_db_version" does not exist at character 3613012026-09-10 17:38:52.490 UTC [1249] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13022026/09/10 17:38:52 INFO Vacuumed table table=pending_objects13032026/09/10 17:38:52 INFO Vacuumed table table=multipart_uploads13042026/09/10 17:38:52 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst13052026/09/10 17:38:52 INFO Received uploads request method=POST path=/api/pending_closures13062026/09/10 17:38:52 OK 20251218171726_add_pins.sql (7.07ms)1307--- PASS: TestPresignedUploadRegisteredBeforeCommit (0.48s)1308=== CONT TestMultipartCleanup13092026-09-10 17:38:52.498 UTC [1250] ERROR: relation "goose_db_version" does not exist at character 3613102026-09-10 17:38:52.498 UTC [1250] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13112026/09/10 17:38:52 INFO Vacuumed table table=closures13122026/09/10 17:38:52 OK 20260628120000_add_object_size_and_stats.sql (2.96ms)13132026/09/10 17:38:52 INFO Vacuumed table table=objects13142026/09/10 17:38:52 OK 20260905000000_add_claims.sql (2.71ms)13152026/09/10 17:38:52 goose: successfully migrated database to version: 2026090500000013162026/09/10 17:38:52 INFO Received uploads request method=POST path=/api/pending_closures13172026/09/10 17:38:52 OK 1_commit_pending_closure.sql (2.45ms)13182026/09/10 17:38:52 OK 2_object_stats_trigger.sql (1.67ms)13192026/09/10 17:38:52 goose: up to current file version: 213202026/09/10 17:38:52 OK 20241026095416_initial_model.sql (10.04ms)13212026/09/10 17:38:52 OK 20251210153512_drop_unused_gin_index.sql (1.97ms)13222026/09/10 17:38:52 OK 20241026095416_initial_model.sql (9.16ms)13232026/09/10 17:38:52 OK 20251218171726_add_pins.sql (3.26ms)13242026/09/10 17:38:52 OK 20251210153512_drop_unused_gin_index.sql (2.06ms)13252026/09/10 17:38:52 OK 20260628120000_add_object_size_and_stats.sql (5.16ms)13262026/09/10 17:38:52 OK 20251218171726_add_pins.sql (3.77ms)13272026/09/10 17:38:52 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001328--- PASS: TestService_createPendingClosureHandler (0.90s)1329=== CONT TestReadProxyHead13302026-09-10 17:38:52.523 UTC [1271] ERROR: relation "goose_db_version" does not exist at character 3613312026-09-10 17:38:52.523 UTC [1271] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13322026/09/10 17:38:52 OK 20260628120000_add_object_size_and_stats.sql (4.52ms)13332026/09/10 17:38:52 OK 20260905000000_add_claims.sql (5.95ms)13342026/09/10 17:38:52 goose: successfully migrated database to version: 2026090500000013352026/09/10 17:38:52 INFO Received uploads request method=POST path=/api/pending_closures13362026/09/10 17:38:52 OK 20260905000000_add_claims.sql (3.75ms)13372026/09/10 17:38:52 goose: successfully migrated database to version: 2026090500000013382026/09/10 17:38:52 OK 1_commit_pending_closure.sql (3.05ms)13392026/09/10 17:38:52 OK 2_object_stats_trigger.sql (1.46ms)13402026/09/10 17:38:52 goose: up to current file version: 213412026/09/10 17:38:52 OK 1_commit_pending_closure.sql (2.09ms)13422026/09/10 17:38:52 OK 2_object_stats_trigger.sql (834.02µs)13432026/09/10 17:38:52 goose: up to current file version: 213442026/09/10 17:38:52 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"13452026/09/10 17:38:52 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13462026/09/10 17:38:52 OK 20241026095416_initial_model.sql (8.79ms)13472026/09/10 17:38:52 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=YzA4YzgyZjMtZjc1OS00ZDlmLWIzZTUtMWIyNzkyMjYzODE5LjlhNWVhM2FlLWU1ZWItNGY1Ny1hY2IxLTBjNjkzNTJlMWU3NngxNzg5MDYxOTMyNTEwNDc3OTc213482026/09/10 17:38:52 OK 20251210153512_drop_unused_gin_index.sql (1.82ms)13492026/09/10 17:38:52 INFO Received uploads request method=POST path=/api/pending_closures13502026/09/10 17:38:52 OK 20251218171726_add_pins.sql (13.86ms)13512026/09/10 17:38:52 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=YzA4YzgyZjMtZjc1OS00ZDlmLWIzZTUtMWIyNzkyMjYzODE5LjlhNWVhM2FlLWU1ZWItNGY1Ny1hY2IxLTBjNjkzNTJlMWU3NngxNzg5MDYxOTMyNTEwNDc3OTc2 parts=11352--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (0.50s)1353=== CONT TestReadProxyInvalidPath13542026/09/10 17:38:52 OK 20260628120000_add_object_size_and_stats.sql (5.58ms)13552026/09/10 17:38:52 OK 20260905000000_add_claims.sql (4.91ms)13562026/09/10 17:38:52 goose: successfully migrated database to version: 202609050000001357--- PASS: TestReadRedirectUsesPublicS3URL (0.45s)1358=== CONT TestOrphanedObjectsGC13592026/09/10 17:38:52 INFO Received uploads request method=POST path=/api/pending_closures13602026/09/10 17:38:52 OK 1_commit_pending_closure.sql (5.54ms)13612026/09/10 17:38:52 OK 2_object_stats_trigger.sql (2.4ms)13622026/09/10 17:38:52 goose: up to current file version: 213632026/09/10 17:38:52 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13642026/09/10 17:38:52 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)13652026/09/10 17:38:52 INFO Uploading 8yr2q0df4gjryblhznirdj1jdg2iwyaa-ca-test (144B)13662026/09/10 17:38:52 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13672026-09-10 17:38:52.583 UTC [1313] ERROR: relation "goose_db_version" does not exist at character 3613682026-09-10 17:38:52.583 UTC [1313] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13692026/09/10 17:38:52 WARN Failed to register uploaded object key=log/vcfbmfnma3g7bzqzcgg974q6y14dh5zp-ca-test.drv error="server returned 404: 404 page not found\n"1370--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.45s)1371=== CONT TestReadProxy40413722026/09/10 17:38:52 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"13732026/09/10 17:38:52 WARN Failed to register uploaded object key=8yr2q0df4gjryblhznirdj1jdg2iwyaa.ls error="server returned 404: 404 page not found\n"13742026/09/10 17:38:52 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign13752026/09/10 17:38:52 INFO Signed narinfos id=1 count=113762026/09/10 17:38:52 INFO Uploading 1 narinfos13772026/09/10 17:38:52 WARN Failed to register uploaded object key=8yr2q0df4gjryblhznirdj1jdg2iwyaa.narinfo error="server returned 404: 404 page not found\n"13782026/09/10 17:38:52 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete13792026/09/10 17:38:52 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=YzA4YzgyZjMtZjc1OS00ZDlmLWIzZTUtMWIyNzkyMjYzODE5LjNjNmU2NzFiLTZmMWItNGVlNC1hYTZlLTJiY2Q2YjFiMjYyNHgxNzg5MDYxOTMyMjcxOTE2Mjky parts=1013802026/09/10 17:38:52 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete13812026/09/10 17:38:52 INFO Completed multipart upload object_key=nar/0000000000000000000000000000001700000000000000000000.nar.zst upload_id=YzA4YzgyZjMtZjc1OS00ZDlmLWIzZTUtMWIyNzkyMjYzODE5LjRlMmVjODJiLTZjMmMtNDZlZS05OGEzLWIzYmUzMGQxZmMyYngxNzg5MDYxOTMyMjYwNTgzMDY4 parts=1013822026/09/10 17:38:52 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete13832026/09/10 17:38:52 OK 20241026095416_initial_model.sql (9.19ms)13842026/09/10 17:38:52 INFO Completed upload id=113852026/09/10 17:38:52 INFO Completed upload id=113862026/09/10 17:38:52 OK 20251210153512_drop_unused_gin_index.sql (1.57ms)13872026/09/10 17:38:52 WARN claim: cannot clear write deadline error="feature not supported"13882026/09/10 17:38:52 INFO Completed upload id=113892026/09/10 17:38:52 INFO Received uploads request method=POST path=/api/pending_closures13902026/09/10 17:38:52 INFO Upload complete. (97ms)13912026-09-10 17:38:52.602 UTC [1316] ERROR: relation "goose_db_version" does not exist at character 3613922026-09-10 17:38:52.602 UTC [1316] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13932026/09/10 17:38:52 OK 20251218171726_add_pins.sql (3.17ms)1394=== NAME TestClientCADerivations1395 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations1134066859/001/store/8yr2q0df4gjryblhznirdj1jdg2iwyaa-ca-test1396 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1397 Compression: zstd1398 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1399 NarSize: 1441400 References: 1401 Deriver: /build/TestClientCADerivations1134066859/001/store/vcfbmfnma3g7bzqzcgg974q6y14dh5zp-ca-test.drv1402 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n14032026/09/10 17:38:52 INFO Received uploads request method=POST path=/api/pending_closures1404 client_ca_test.go:185: Checking for realisation files in S3...1405 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1406 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache14072026/09/10 17:38:52 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo14082026/09/10 17:38:52 WARN Found objects in DB but missing from S3, will re-upload count=114092026/09/10 17:38:52 OK 20260628120000_add_object_size_and_stats.sql (3.98ms)1410--- PASS: TestService_verifyS3Integrity (0.99s)1411=== CONT TestObjectStatsTrigger14122026/09/10 17:38:52 OK 20260905000000_add_claims.sql (3.21ms)14132026/09/10 17:38:52 goose: successfully migrated database to version: 2026090500000014142026/09/10 17:38:52 OK 1_commit_pending_closure.sql (2.46ms)14152026/09/10 17:38:52 OK 2_object_stats_trigger.sql (1.81ms)14162026/09/10 17:38:52 goose: up to current file version: 21417--- PASS: TestReadProxyRangeRequest (0.44s)1418=== CONT TestReadProxyNarStreaming14192026/09/10 17:38:52 INFO Aborted multipart uploads count=014202026/09/10 17:38:52 WARN Force mode enabled - objects will be deleted immediately without grace period14212026/09/10 17:38:52 OK 20241026095416_initial_model.sql (9.6ms)14222026/09/10 17:38:52 OK 20251210153512_drop_unused_gin_index.sql (2.36ms)14232026/09/10 17:38:52 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=014242026/09/10 17:38:52 OK 20251218171726_add_pins.sql (3.21ms)14252026/09/10 17:38:52 INFO Vacuumed table table=pending_closures1426=== RUN TestService_RequireScope_OIDC/builder_may_write1427=== PAUSE TestService_RequireScope_OIDC/builder_may_write1428=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1429=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1430=== RUN TestService_RequireScope_OIDC/ops_may_admin1431=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1432=== RUN TestService_RequireScope_OIDC/ops_may_not_write1433=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1434=== RUN TestService_RequireScope_OIDC/reader_may_not_write1435=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1436=== RUN TestService_RequireScope_OIDC/static_token_may_admin1437=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1438=== RUN TestService_RequireScope_OIDC/static_token_may_write1439=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1440=== RUN TestService_RequireScope_OIDC/reader_may_read1441=== PAUSE TestService_RequireScope_OIDC/reader_may_read1442=== RUN TestService_RequireScope_OIDC/writer_implies_read1443=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1444=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1445=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1446=== CONT TestReadProxyNarinfoAlreadyDecompressed14472026/09/10 17:38:52 OK 20260628120000_add_object_size_and_stats.sql (20.37ms)14482026/09/10 17:38:52 OK 20260905000000_add_claims.sql (3.75ms)14492026/09/10 17:38:52 goose: successfully migrated database to version: 2026090500000014502026/09/10 17:38:52 INFO Vacuumed table table=pending_objects14512026/09/10 17:38:52 OK 1_commit_pending_closure.sql (4.02ms)14522026-09-10 17:38:52.654 UTC [1344] ERROR: relation "goose_db_version" does not exist at character 3614532026-09-10 17:38:52.654 UTC [1344] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14542026-09-10 17:38:52.655 UTC [1345] ERROR: relation "goose_db_version" does not exist at character 3614552026-09-10 17:38:52.655 UTC [1345] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14562026/09/10 17:38:52 INFO Vacuumed table table=multipart_uploads14572026/09/10 17:38:52 OK 2_object_stats_trigger.sql (2.4ms)14582026/09/10 17:38:52 goose: up to current file version: 214592026/09/10 17:38:52 INFO Vacuumed table table=closures14602026/09/10 17:38:52 INFO Vacuumed table table=objects1461--- PASS: TestClaim_InputsTouched (1.05s)1462=== CONT TestService_NativeMTLS1463--- PASS: TestReadRedirectKeepsNarinfoProxied (0.45s)1464=== CONT TestServerTLSConfig1465=== RUN TestServerTLSConfig/no_client_CA1466=== PAUSE TestServerTLSConfig/no_client_CA1467=== RUN TestServerTLSConfig/missing_CA_file1468=== PAUSE TestServerTLSConfig/missing_CA_file1469=== RUN TestServerTLSConfig/not_a_PEM_file1470=== PAUSE TestServerTLSConfig/not_a_PEM_file1471=== CONT TestReadProxyNarinfo14722026/09/10 17:38:52 OK 20241026095416_initial_model.sql (9.96ms)14732026/09/10 17:38:52 OK 20241026095416_initial_model.sql (9.46ms)14742026-09-10 17:38:52.670 UTC [1374] ERROR: relation "goose_db_version" does not exist at character 3614752026-09-10 17:38:52.670 UTC [1374] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14762026/09/10 17:38:52 OK 20251210153512_drop_unused_gin_index.sql (1.79ms)14772026/09/10 17:38:52 OK 20251210153512_drop_unused_gin_index.sql (2.86ms)14782026/09/10 17:38:52 OK 20251218171726_add_pins.sql (3.89ms)14792026/09/10 17:38:52 OK 20251218171726_add_pins.sql (2.59ms)14802026/09/10 17:38:52 INFO Received complete multipart upload request method=POST path=/api/multipart/complete14812026/09/10 17:38:52 OK 20260628120000_add_object_size_and_stats.sql (4.53ms)14822026/09/10 17:38:52 OK 20260628120000_add_object_size_and_stats.sql (4.86ms)14832026/09/10 17:38:52 OK 20260905000000_add_claims.sql (4.17ms)14842026/09/10 17:38:52 goose: successfully migrated database to version: 202609050000001485--- PASS: TestReadRedirectNar (0.35s)1486=== CONT TestService_AuthMiddleware_OIDC14872026/09/10 17:38:52 OK 20260905000000_add_claims.sql (3.72ms)14882026/09/10 17:38:52 goose: successfully migrated database to version: 2026090500000014892026/09/10 17:38:52 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:40945/oidc14902026/09/10 17:38:52 OK 1_commit_pending_closure.sql (2.9ms)14912026/09/10 17:38:52 OK 1_commit_pending_closure.sql (3.53ms)14922026/09/10 17:38:52 OK 20241026095416_initial_model.sql (10.87ms)14932026/09/10 17:38:52 OK 2_object_stats_trigger.sql (1.82ms)14942026/09/10 17:38:52 goose: up to current file version: 214952026/09/10 17:38:52 OK 2_object_stats_trigger.sql (1.64ms)14962026/09/10 17:38:52 goose: up to current file version: 214972026/09/10 17:38:52 OK 20251210153512_drop_unused_gin_index.sql (1.82ms)14982026/09/10 17:38:52 OK 20251218171726_add_pins.sql (17.81ms)14992026/09/10 17:38:52 OK 20260628120000_add_object_size_and_stats.sql (3.82ms)15002026/09/10 17:38:52 INFO Completed multipart upload object_key=nar/0000000000000000000000000000001100000000000000000000.nar.zst upload_id=YzA4YzgyZjMtZjc1OS00ZDlmLWIzZTUtMWIyNzkyMjYzODE5LmQ4MTM3OTJhLWJlMTAtNDJjYi04OTNmLTUzYmIzYmZkYjQ1MngxNzg5MDYxOTMyMzU2NDA2Nzgw parts=1015012026/09/10 17:38:52 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete15022026-09-10 17:38:52.716 UTC [1477] ERROR: relation "goose_db_version" does not exist at character 3615032026-09-10 17:38:52.716 UTC [1477] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15042026/09/10 17:38:52 OK 20260905000000_add_claims.sql (4.72ms)15052026/09/10 17:38:52 goose: successfully migrated database to version: 2026090500000015062026/09/10 17:38:52 OK 1_commit_pending_closure.sql (2.53ms)15072026/09/10 17:38:52 INFO Completed upload id=115082026/09/10 17:38:52 WARN claim: cannot clear write deadline error="feature not supported"15092026/09/10 17:38:52 OK 2_object_stats_trigger.sql (1.11ms)15102026/09/10 17:38:52 goose: up to current file version: 215112026/09/10 17:38:52 WARN claim: cannot clear write deadline error="feature not supported"1512=== NAME TestClientCADerivations1513 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features1514 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable1515 error: binary cache 's3://bucket23?endpoint=http://localhost:34347®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations1134066859/001/store'1516 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 11517--- PASS: TestClaim_GCMarkedOutputCountsAsAbsent (1.11s)1518=== CONT TestIsValidCachePath1519=== RUN TestIsValidCachePath/narinfo1520=== PAUSE TestIsValidCachePath/narinfo1521=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars1522=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars1523=== RUN TestIsValidCachePath/nar_zst1524=== PAUSE TestIsValidCachePath/nar_zst1525=== RUN TestIsValidCachePath/nar_xz1526=== PAUSE TestIsValidCachePath/nar_xz1527=== RUN TestIsValidCachePath/nar_bz21528=== PAUSE TestIsValidCachePath/nar_bz21529=== RUN TestIsValidCachePath/nar_uncompressed1530=== PAUSE TestIsValidCachePath/nar_uncompressed1531=== RUN TestIsValidCachePath/ls1532=== PAUSE TestIsValidCachePath/ls1533=== RUN TestIsValidCachePath/log1534=== PAUSE TestIsValidCachePath/log1535=== RUN TestIsValidCachePath/realisation1536=== PAUSE TestIsValidCachePath/realisation1537=== RUN TestIsValidCachePath/nix-cache-info1538=== PAUSE TestIsValidCachePath/nix-cache-info1539=== RUN TestIsValidCachePath/index.html1540=== PAUSE TestIsValidCachePath/index.html1541=== RUN TestIsValidCachePath/traversal_parent1542=== PAUSE TestIsValidCachePath/traversal_parent1543=== RUN TestIsValidCachePath/traversal_in_middle1544=== PAUSE TestIsValidCachePath/traversal_in_middle1545=== RUN TestIsValidCachePath/invalid_char_e1546=== PAUSE TestIsValidCachePath/invalid_char_e1547=== RUN TestIsValidCachePath/invalid_char_u1548=== PAUSE TestIsValidCachePath/invalid_char_u1549=== RUN TestIsValidCachePath/random_path1550=== PAUSE TestIsValidCachePath/random_path1551=== RUN TestIsValidCachePath/empty1552=== PAUSE TestIsValidCachePath/empty1553=== RUN TestIsValidCachePath/leading_slash1554=== PAUSE TestIsValidCachePath/leading_slash1555=== RUN TestIsValidCachePath/wrong_extension1556=== PAUSE TestIsValidCachePath/wrong_extension1557=== RUN TestIsValidCachePath/short_hash1558=== PAUSE TestIsValidCachePath/short_hash1559=== CONT TestResurrectedObjectNotDeleted15602026-09-10 17:38:52.731 UTC [1547] ERROR: relation "goose_db_version" does not exist at character 3615612026-09-10 17:38:52.731 UTC [1547] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15622026/09/10 17:38:52 INFO Aborted multipart uploads count=015632026/09/10 17:38:52 OK 20241026095416_initial_model.sql (11.05ms)1564--- PASS: TestClientCADerivations (1.12s)15652026-09-10 17:38:52.734 UTC [1549] ERROR: relation "goose_db_version" does not exist at character 3615662026-09-10 17:38:52.734 UTC [1549] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1567=== CONT TestOrphanedObjectsGCStressTest15682026/09/10 17:38:52 OK 20251210153512_drop_unused_gin_index.sql (1.89ms)15692026/09/10 17:38:52 WARN Force mode enabled - objects will be deleted immediately without grace period15702026/09/10 17:38:52 WARN claim: cannot clear write deadline error="feature not supported"15712026/09/10 17:38:52 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=015722026/09/10 17:38:52 INFO Vacuumed table table=pending_closures15732026/09/10 17:38:52 INFO Vacuumed table table=pending_objects15742026/09/10 17:38:52 INFO Vacuumed table table=multipart_uploads15752026/09/10 17:38:52 OK 20251218171726_add_pins.sql (5.4ms)15762026/09/10 17:38:52 INFO Vacuumed table table=closures15772026/09/10 17:38:52 INFO Vacuumed table table=objects15782026/09/10 17:38:52 OK 20260628120000_add_object_size_and_stats.sql (3.97ms)15792026/09/10 17:38:52 OK 20241026095416_initial_model.sql (9.79ms)1580--- PASS: TestGCMetrics (0.35s)1581=== CONT TestMetricsInventory15822026/09/10 17:38:52 OK 20260905000000_add_claims.sql (3.67ms)15832026/09/10 17:38:52 goose: successfully migrated database to version: 2026090500000015842026/09/10 17:38:52 OK 20241026095416_initial_model.sql (9.23ms)15852026/09/10 17:38:52 OK 20251210153512_drop_unused_gin_index.sql (3.05ms)15862026/09/10 17:38:52 OK 1_commit_pending_closure.sql (2.33ms)15872026/09/10 17:38:52 OK 20251210153512_drop_unused_gin_index.sql (1.59ms)1588--- PASS: TestReadProxyRootRedirectsToIndexHTML (0.33s)1589=== CONT TestCacheStatsHandler15902026/09/10 17:38:52 INFO Received complete multipart upload request method=POST path=/api/multipart/complete15912026/09/10 17:38:52 OK 2_object_stats_trigger.sql (1.7ms)15922026/09/10 17:38:52 goose: up to current file version: 215932026/09/10 17:38:52 OK 20251218171726_add_pins.sql (3.72ms)15942026/09/10 17:38:52 OK 20251218171726_add_pins.sql (4.24ms)15952026/09/10 17:38:52 OK 20260628120000_add_object_size_and_stats.sql (3.74ms)15962026-09-10 17:38:52.758 UTC [1557] ERROR: relation "goose_db_version" does not exist at character 3615972026-09-10 17:38:52.758 UTC [1557] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15982026/09/10 17:38:52 OK 20260628120000_add_object_size_and_stats.sql (3.9ms)15992026-09-10 17:38:52.760 UTC [1558] ERROR: relation "goose_db_version" does not exist at character 3616002026-09-10 17:38:52.760 UTC [1558] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16012026/09/10 17:38:52 OK 20260905000000_add_claims.sql (3.47ms)16022026/09/10 17:38:52 goose: successfully migrated database to version: 2026090500000016032026/09/10 17:38:52 OK 20260905000000_add_claims.sql (3.73ms)16042026/09/10 17:38:52 goose: successfully migrated database to version: 2026090500000016052026/09/10 17:38:52 OK 1_commit_pending_closure.sql (3.32ms)16062026/09/10 17:38:52 OK 2_object_stats_trigger.sql (1.77ms)16072026/09/10 17:38:52 goose: up to current file version: 216082026/09/10 17:38:52 OK 1_commit_pending_closure.sql (2.79ms)16092026/09/10 17:38:52 OK 2_object_stats_trigger.sql (1.36ms)16102026/09/10 17:38:52 goose: up to current file version: 21611--- PASS: TestReadProxyConditionalGet (0.34s)1612=== CONT TestPinProtectsFromGC16132026/09/10 17:38:52 INFO Completed multipart upload object_key=nar/0000000000000000000000000000001600000000000000000000.nar.zst upload_id=YzA4YzgyZjMtZjc1OS00ZDlmLWIzZTUtMWIyNzkyMjYzODE5LjhlMGQ2MjBlLTA3MGMtNDczMi1iMzY2LWYwZmNhNmVmNTQ4NXgxNzg5MDYxOTMyNDA4NDIxNzMz parts=1016142026/09/10 17:38:52 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign16152026/09/10 17:38:52 INFO Signed narinfos id=1 count=116162026/09/10 17:38:52 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete16172026/09/10 17:38:52 OK 20241026095416_initial_model.sql (22.87ms)16182026/09/10 17:38:52 OK 20241026095416_initial_model.sql (21.42ms)16192026/09/10 17:38:52 OK 20251210153512_drop_unused_gin_index.sql (2.48ms)16202026/09/10 17:38:52 OK 20251210153512_drop_unused_gin_index.sql (2.44ms)16212026/09/10 17:38:52 INFO Received uploads request method=POST path=/api/pending_closures16222026/09/10 17:38:52 INFO Completed upload id=11623--- PASS: TestClaim_TwoInstances (1.18s)1624=== CONT TestNARDeduplicationMetadataUploadBug16252026/09/10 17:38:52 OK 20251218171726_add_pins.sql (5.59ms)16262026/09/10 17:38:52 OK 20251218171726_add_pins.sql (5.5ms)16272026/09/10 17:38:52 OK 20260628120000_add_object_size_and_stats.sql (4.28ms)16282026/09/10 17:38:52 OK 20260628120000_add_object_size_and_stats.sql (5.33ms)16292026/09/10 17:38:52 OK 20260905000000_add_claims.sql (3.89ms)16302026/09/10 17:38:52 goose: successfully migrated database to version: 2026090500000016312026/09/10 17:38:52 OK 20260905000000_add_claims.sql (4.47ms)16322026/09/10 17:38:52 goose: successfully migrated database to version: 2026090500000016332026/09/10 17:38:52 OK 1_commit_pending_closure.sql (3.29ms)16342026/09/10 17:38:52 OK 1_commit_pending_closure.sql (2.4ms)16352026/09/10 17:38:52 OK 2_object_stats_trigger.sql (1.37ms)16362026/09/10 17:38:52 goose: up to current file version: 216372026/09/10 17:38:52 OK 2_object_stats_trigger.sql (1.48ms)16382026/09/10 17:38:52 goose: up to current file version: 216392026-09-10 17:38:52.815 UTC [1565] ERROR: relation "goose_db_version" does not exist at character 3616402026-09-10 17:38:52.815 UTC [1565] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1641--- PASS: TestReadProxyHead (0.30s)1642=== CONT TestResolveDBConnectionString1643=== RUN TestResolveDBConnectionString/flag_wins1644=== PAUSE TestResolveDBConnectionString/flag_wins1645=== RUN TestResolveDBConnectionString/file_when_flag_empty1646=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1647=== RUN TestResolveDBConnectionString/missing_file_is_an_error1648=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1649=== RUN TestResolveDBConnectionString/PGHOST_allows_empty1650=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1651=== RUN TestResolveDBConnectionString/nothing_configured1652=== PAUSE TestResolveDBConnectionString/nothing_configured1653=== CONT TestClientWithDependencies16542026-09-10 17:38:52.824 UTC [1566] ERROR: relation "goose_db_version" does not exist at character 3616552026-09-10 17:38:52.824 UTC [1566] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16562026-09-10 17:38:52.826 UTC [1567] ERROR: relation "goose_db_version" does not exist at character 3616572026-09-10 17:38:52.826 UTC [1567] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1658--- PASS: TestReadProxyInvalidPath (0.28s)1659=== CONT TestCacheConfigHandler1660=== RUN TestCacheConfigHandler/full_config,_no_issuer1661=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1662=== RUN TestCacheConfigHandler/no_cache_url_configured1663=== PAUSE TestCacheConfigHandler/no_cache_url_configured1664=== RUN TestCacheConfigHandler/no_signing_keys1665=== PAUSE TestCacheConfigHandler/no_signing_keys1666=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1667=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1668=== CONT TestClientMultipleUploads16692026/09/10 17:38:52 OK 20241026095416_initial_model.sql (24.1ms)16702026/09/10 17:38:52 OK 20251210153512_drop_unused_gin_index.sql (2.03ms)16712026/09/10 17:38:52 OK 20251218171726_add_pins.sql (4.37ms)16722026/09/10 17:38:52 OK 20241026095416_initial_model.sql (8.88ms)16732026/09/10 17:38:52 OK 20251210153512_drop_unused_gin_index.sql (2.35ms)16742026/09/10 17:38:52 OK 20241026095416_initial_model.sql (9.69ms)16752026-09-10 17:38:52.858 UTC [1573] ERROR: relation "goose_db_version" does not exist at character 3616762026-09-10 17:38:52.858 UTC [1573] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16772026-09-10 17:38:52.858 UTC [1572] ERROR: relation "goose_db_version" does not exist at character 3616782026-09-10 17:38:52.858 UTC [1572] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16792026/09/10 17:38:52 OK 20260628120000_add_object_size_and_stats.sql (5.38ms)16802026/09/10 17:38:52 OK 20251218171726_add_pins.sql (4.01ms)16812026/09/10 17:38:52 OK 20251210153512_drop_unused_gin_index.sql (2.48ms)16822026/09/10 17:38:52 OK 20251218171726_add_pins.sql (3.36ms)16832026/09/10 17:38:52 OK 20260628120000_add_object_size_and_stats.sql (4.63ms)16842026/09/10 17:38:52 OK 20260905000000_add_claims.sql (5.65ms)16852026/09/10 17:38:52 goose: successfully migrated database to version: 2026090500000016862026/09/10 17:38:52 OK 1_commit_pending_closure.sql (2.17ms)16872026/09/10 17:38:52 OK 20260905000000_add_claims.sql (3.38ms)16882026/09/10 17:38:52 goose: successfully migrated database to version: 2026090500000016892026/09/10 17:38:52 OK 20260628120000_add_object_size_and_stats.sql (4.51ms)16902026/09/10 17:38:52 OK 2_object_stats_trigger.sql (2.15ms)16912026/09/10 17:38:52 goose: up to current file version: 216922026/09/10 17:38:52 OK 1_commit_pending_closure.sql (2.15ms)16932026/09/10 17:38:52 OK 20260905000000_add_claims.sql (3.97ms)16942026/09/10 17:38:52 goose: successfully migrated database to version: 2026090500000016952026/09/10 17:38:52 OK 2_object_stats_trigger.sql (2.73ms)16962026/09/10 17:38:52 goose: up to current file version: 216972026/09/10 17:38:52 INFO Received complete multipart upload request method=POST path=/api/multipart/complete16982026/09/10 17:38:52 OK 20241026095416_initial_model.sql (8.92ms)16992026/09/10 17:38:52 OK 20241026095416_initial_model.sql (8.89ms)17002026/09/10 17:38:52 OK 1_commit_pending_closure.sql (2.6ms)17012026/09/10 17:38:52 OK 20251210153512_drop_unused_gin_index.sql (1.71ms)17022026/09/10 17:38:52 OK 20251210153512_drop_unused_gin_index.sql (1.76ms)17032026/09/10 17:38:52 OK 2_object_stats_trigger.sql (1.76ms)17042026/09/10 17:38:52 goose: up to current file version: 217052026/09/10 17:38:52 OK 20251218171726_add_pins.sql (2.72ms)17062026/09/10 17:38:52 OK 20251218171726_add_pins.sql (3.81ms)17072026/09/10 17:38:52 OK 20260628120000_add_object_size_and_stats.sql (3.07ms)17082026/09/10 17:38:52 OK 20260628120000_add_object_size_and_stats.sql (2.84ms)17092026/09/10 17:38:52 OK 20260905000000_add_claims.sql (3.09ms)17102026/09/10 17:38:52 goose: successfully migrated database to version: 2026090500000017112026/09/10 17:38:52 OK 20260905000000_add_claims.sql (3.76ms)17122026/09/10 17:38:52 goose: successfully migrated database to version: 2026090500000017132026-09-10 17:38:52.887 UTC [1574] ERROR: relation "goose_db_version" does not exist at character 3617142026-09-10 17:38:52.887 UTC [1574] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17152026/09/10 17:38:52 OK 1_commit_pending_closure.sql (3.16ms)17162026/09/10 17:38:52 OK 1_commit_pending_closure.sql (2.52ms)17172026-09-10 17:38:52.890 UTC [1575] ERROR: relation "goose_db_version" does not exist at character 3617182026-09-10 17:38:52.890 UTC [1575] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17192026/09/10 17:38:52 OK 2_object_stats_trigger.sql (2.62ms)17202026/09/10 17:38:52 goose: up to current file version: 217212026/09/10 17:38:52 OK 2_object_stats_trigger.sql (2.6ms)17222026/09/10 17:38:52 goose: up to current file version: 21723--- PASS: TestReadProxy404 (0.31s)1724=== CONT TestClientErrorHandling/InvalidStorePath17252026/09/10 17:38:52 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=YzA4YzgyZjMtZjc1OS00ZDlmLWIzZTUtMWIyNzkyMjYzODE5LmY1YzdlYmY1LTc1NTEtNGM0OC05NDI1LTI1MmEwYjQ0ZDgyOXgxNzg5MDYxOTMyNDY2OTA5ODA2 parts=1217262026/09/10 17:38:52 INFO Received uploads request method=POST path=/api/pending_closures17272026/09/10 17:38:52 INFO Received cleanup request method=DELETE path=/api/pending_closures17282026/09/10 17:38:52 INFO Aborted multipart uploads count=11729--- PASS: TestCompletedNarNotReofferedAcrossClosures (0.90s)1730=== CONT TestClientErrorHandling/ServerNotAvailable17312026/09/10 17:38:52 OK 20241026095416_initial_model.sql (22.1ms)17322026/09/10 17:38:52 OK 20241026095416_initial_model.sql (24.81ms)1733--- PASS: TestMultipartCleanup (0.42s)1734=== CONT TestClientErrorHandling/InvalidAuthToken17352026/09/10 17:38:52 OK 20251210153512_drop_unused_gin_index.sql (1.36ms)17362026/09/10 17:38:52 OK 20251210153512_drop_unused_gin_index.sql (3.24ms)17372026/09/10 17:38:52 OK 20251218171726_add_pins.sql (3.02ms)17382026/09/10 17:38:52 OK 20251218171726_add_pins.sql (4.74ms)17392026/09/10 17:38:52 OK 20260628120000_add_object_size_and_stats.sql (4.05ms)17402026-09-10 17:38:52.928 UTC [1580] ERROR: relation "goose_db_version" does not exist at character 3617412026-09-10 17:38:52.928 UTC [1580] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17422026-09-10 17:38:52.928 UTC [1581] ERROR: relation "goose_db_version" does not exist at character 3617432026-09-10 17:38:52.928 UTC [1581] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1744--- PASS: TestObjectStatsTrigger (0.32s)1745=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info17462026/09/10 17:38:52 INFO Received uploads request method=POST path=/1747=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key17482026/09/10 17:38:52 INFO Received complete multipart upload request method=POST path=/1749=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key17502026/09/10 17:38:52 OK 20260905000000_add_claims.sql (3.55ms)17512026/09/10 17:38:52 goose: successfully migrated database to version: 2026090500000017522026/09/10 17:38:52 INFO Received request for more parts method=POST path=/1753=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal17542026/09/10 17:38:52 INFO Received uploads request method=POST path=/1755--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)1756 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1757 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1758 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1759 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1760=== CONT TestIsValidUploadKey/narinfo1761=== CONT TestIsValidUploadKey/realisation_plus_in_output1762=== CONT TestIsValidUploadKey/unknown_type1763=== CONT TestIsValidUploadKey/empty_key1764=== CONT TestIsValidUploadKey/absolute1765=== CONT TestIsValidUploadKey/traversal_nar1766=== CONT TestIsValidUploadKey/traversal1767=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1768=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1769=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1770=== CONT TestIsValidUploadKey/index.html1771=== CONT TestIsValidUploadKey/build_log_home-manager_file1772=== CONT TestIsValidUploadKey/nix-cache-info1773=== CONT TestIsValidUploadKey/realisation1774=== CONT TestIsValidUploadKey/build_log_equals1775=== CONT TestIsValidUploadKey/nar_plain1776=== CONT TestIsValidUploadKey/build_log_question_mark1777=== CONT TestIsValidUploadKey/build_log1778=== CONT TestIsValidUploadKey/build_log_plus_in_name1779=== CONT TestIsValidUploadKey/listing1780=== CONT TestIsValidUploadKey/nar_zst1781=== CONT TestIsValidUploadKey/nar_xz1782--- PASS: TestIsValidUploadKey (0.08s)1783 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1784 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1785 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1786 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1787 --- PASS: TestIsValidUploadKey/absolute (0.00s)1788 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1789 --- PASS: TestIsValidUploadKey/traversal (0.00s)1790 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1791 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1792 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1793 --- PASS: TestIsValidUploadKey/index.html (0.00s)1794 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1795 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1796 --- PASS: TestIsValidUploadKey/realisation (0.00s)1797 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1798 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1799 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1800 --- PASS: TestIsValidUploadKey/build_log (0.00s)1801 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1802 --- PASS: TestIsValidUploadKey/listing (0.00s)1803 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1804 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1805=== CONT TestProxyWriteTimeout/narinfo1806=== CONT TestProxyWriteTimeout/10_GiB_nar1807=== CONT TestProxyWriteTimeout/unknown_size1808=== CONT TestProxyWriteTimeout/1_GiB_nar1809--- PASS: TestProxyWriteTimeout (0.00s)1810 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1811 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1812 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1813 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1814=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts18152026/09/10 17:38:52 INFO Received request for more parts method=POST path=/18162026/09/10 17:38:52 OK 20260628120000_add_object_size_and_stats.sql (5.15ms)18172026/09/10 17:38:52 OK 1_commit_pending_closure.sql (1.91ms)18182026/09/10 17:38:52 OK 2_object_stats_trigger.sql (1.47ms)18192026/09/10 17:38:52 goose: up to current file version: 218202026/09/10 17:38:52 OK 20260905000000_add_claims.sql (3.72ms)18212026/09/10 17:38:52 goose: successfully migrated database to version: 2026090500000018222026/09/10 17:38:52 OK 1_commit_pending_closure.sql (1.97ms)18232026/09/10 17:38:52 OK 2_object_stats_trigger.sql (1.55ms)18242026/09/10 17:38:52 goose: up to current file version: 218252026/09/10 17:38:52 OK 20241026095416_initial_model.sql (8.07ms)18262026/09/10 17:38:52 OK 20241026095416_initial_model.sql (8.66ms)18272026/09/10 17:38:52 OK 20251210153512_drop_unused_gin_index.sql (1.32ms)18282026/09/10 17:38:52 OK 20251210153512_drop_unused_gin_index.sql (1.92ms)18292026/09/10 17:38:52 OK 20251218171726_add_pins.sql (3.25ms)18302026/09/10 17:38:52 OK 20251218171726_add_pins.sql (3.7ms)18312026/09/10 17:38:52 OK 20260628120000_add_object_size_and_stats.sql (3.99ms)1832--- PASS: TestReadProxyNarStreaming (0.34s)1833=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart18342026/09/10 17:38:52 INFO Received complete multipart upload request method=POST path=/18352026/09/10 17:38:52 OK 20260628120000_add_object_size_and_stats.sql (3.94ms)18362026/09/10 17:38:52 OK 20260905000000_add_claims.sql (3.2ms)18372026/09/10 17:38:52 goose: successfully migrated database to version: 2026090500000018382026/09/10 17:38:52 OK 20260905000000_add_claims.sql (2.62ms)18392026/09/10 17:38:52 goose: successfully migrated database to version: 202609050000001840--- PASS: TestGCBugBareHashReferences (0.56s)1841=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure18422026/09/10 17:38:52 INFO Received uploads request method=POST path=/18432026/09/10 17:38:52 OK 1_commit_pending_closure.sql (1.91ms)18442026/09/10 17:38:52 OK 2_object_stats_trigger.sql (1.25ms)18452026/09/10 17:38:52 goose: up to current file version: 218462026/09/10 17:38:52 OK 1_commit_pending_closure.sql (2.96ms)18472026/09/10 17:38:52 OK 2_object_stats_trigger.sql (1.72ms)18482026/09/10 17:38:52 goose: up to current file version: 21849--- PASS: TestReadProxyNarinfoAlreadyDecompressed (0.34s)1850=== CONT TestParseSingleRange/none1851=== CONT TestParseSingleRange/open-ended1852=== CONT TestParseSingleRange/start_far_past_EOF1853=== CONT TestParseSingleRange/suffix_exceeds_size1854=== CONT TestParseSingleRange/suffix1855=== CONT TestParseSingleRange/start_past_EOF1856=== CONT TestParseSingleRange/end_clamped_to_size1857=== CONT TestParseSingleRange/single_byte1858=== CONT TestParseSingleRange/malformed_both_empty1859=== CONT TestParseSingleRange/closed1860=== CONT TestParseSingleRange/malformed_end_before_start1861=== CONT TestParseSingleRange/multi-range_ignored1862=== CONT TestParseSingleRange/malformed_no_dash1863=== CONT TestParseSingleRange/unknown_unit1864--- PASS: TestParseSingleRange (0.00s)1865 --- PASS: TestParseSingleRange/none (0.00s)1866 --- PASS: TestParseSingleRange/open-ended (0.00s)1867 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1868 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1869 --- PASS: TestParseSingleRange/suffix (0.00s)1870 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1871 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1872 --- PASS: TestParseSingleRange/single_byte (0.00s)1873 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1874 --- PASS: TestParseSingleRange/closed (0.00s)1875 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1876 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1877 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1878 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1879=== CONT TestService_RequireScope_OIDC/builder_may_write18802026-09-10 17:38:52.978 UTC [1600] ERROR: relation "goose_db_version" does not exist at character 3618812026-09-10 17:38:52.978 UTC [1600] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18822026/09/10 17:38:52 INFO OIDC auth successful provider=test scopes=[write]1883=== CONT TestService_RequireScope_OIDC/static_token_may_admin1884=== CONT TestService_RequireScope_OIDC/reader_may_not_write18852026/09/10 17:38:52 INFO OIDC auth successful provider=test scopes=[read]1886=== CONT TestService_RequireScope_OIDC/ops_may_not_write18872026/09/10 17:38:52 INFO OIDC auth successful provider=test scopes=[admin]1888=== CONT TestService_RequireScope_OIDC/ops_may_admin18892026/09/10 17:38:52 INFO OIDC auth successful provider=test scopes=[admin]1890=== CONT TestService_RequireScope_OIDC/builder_may_not_admin18912026/09/10 17:38:52 INFO OIDC auth successful provider=test scopes=[write]1892=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read1893=== CONT TestService_RequireScope_OIDC/static_token_may_write1894=== CONT TestService_RequireScope_OIDC/writer_implies_read18952026/09/10 17:38:52 INFO OIDC auth successful provider=test scopes=[write]1896=== CONT TestService_RequireScope_OIDC/reader_may_read18972026/09/10 17:38:52 INFO OIDC auth successful provider=test scopes=[read]1898=== CONT TestServerTLSConfig/no_client_CA1899=== CONT TestServerTLSConfig/not_a_PEM_file1900--- PASS: TestService_RequireScope_OIDC (0.46s)1901 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)1902 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)1903 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)1904 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)1905 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)1906 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)1907 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)1908 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)1909 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)1910 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)1911=== CONT TestServerTLSConfig/missing_CA_file1912--- PASS: TestServerTLSConfig (0.00s)1913 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1914 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)1915 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1916=== CONT TestIsValidCachePath/narinfo1917=== CONT TestIsValidCachePath/index.html1918=== CONT TestIsValidCachePath/short_hash1919=== CONT TestIsValidCachePath/wrong_extension1920=== CONT TestIsValidCachePath/leading_slash1921=== CONT TestIsValidCachePath/empty1922=== CONT TestIsValidCachePath/random_path1923=== CONT TestIsValidCachePath/invalid_char_u1924=== CONT TestIsValidCachePath/invalid_char_e1925=== CONT TestIsValidCachePath/traversal_in_middle1926=== CONT TestIsValidCachePath/nar_uncompressed1927=== CONT TestIsValidCachePath/traversal_parent1928=== CONT TestIsValidCachePath/nix-cache-info1929=== CONT TestIsValidCachePath/nar_xz1930=== CONT TestIsValidCachePath/realisation1931=== CONT TestIsValidCachePath/nar_bz21932=== CONT TestIsValidCachePath/log1933=== CONT TestIsValidCachePath/nar_zst1934=== CONT TestIsValidCachePath/ls1935=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1936--- PASS: TestIsValidCachePath (0.00s)1937 --- PASS: TestIsValidCachePath/narinfo (0.00s)1938 --- PASS: TestIsValidCachePath/index.html (0.00s)1939 --- PASS: TestIsValidCachePath/short_hash (0.00s)1940 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1941 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1942 --- PASS: TestIsValidCachePath/empty (0.00s)1943 --- PASS: TestIsValidCachePath/random_path (0.00s)1944 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1945 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1946 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1947 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1948 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1949 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1950 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1951 --- PASS: TestIsValidCachePath/realisation (0.00s)1952 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1953 --- PASS: TestIsValidCachePath/log (0.00s)1954 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1955 --- PASS: TestIsValidCachePath/ls (0.00s)1956 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1957=== CONT TestResolveDBConnectionString/flag_wins1958=== CONT TestResolveDBConnectionString/PGHOST_allows_empty1959=== CONT TestResolveDBConnectionString/nothing_configured1960=== CONT TestResolveDBConnectionString/missing_file_is_an_error1961=== CONT TestResolveDBConnectionString/file_when_flag_empty1962=== CONT TestCacheConfigHandler/full_config,_no_issuer1963=== CONT TestCacheConfigHandler/no_signing_keys1964=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1965=== CONT TestCacheConfigHandler/no_cache_url_configured1966--- PASS: TestResolveDBConnectionString (0.00s)1967 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)1968 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)1969 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)1970 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)1971 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)1972--- PASS: TestCacheConfigHandler (0.00s)1973 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)1974 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)1975 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)1976 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)19772026/09/10 17:38:52 OK 20241026095416_initial_model.sql (6.49ms)19782026/09/10 17:38:52 OK 20251210153512_drop_unused_gin_index.sql (898.71µs)19792026-09-10 17:38:52.992 UTC [1619] ERROR: relation "goose_db_version" does not exist at character 3619802026-09-10 17:38:52.992 UTC [1619] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC19812026/09/10 17:38:52 OK 20251218171726_add_pins.sql (3.13ms)19822026/09/10 17:38:52 OK 20260628120000_add_object_size_and_stats.sql (2.64ms)19832026/09/10 17:38:53 OK 20260905000000_add_claims.sql (2.49ms)19842026/09/10 17:38:53 goose: successfully migrated database to version: 202609050000001985--- PASS: TestReadProxyNarinfo (0.34s)19862026/09/10 17:38:53 OK 1_commit_pending_closure.sql (1.89ms)19872026/09/10 17:38:53 OK 2_object_stats_trigger.sql (1.41ms)19882026/09/10 17:38:53 goose: up to current file version: 219892026/09/10 17:38:53 OK 20241026095416_initial_model.sql (7.19ms)19902026/09/10 17:38:53 OK 20251210153512_drop_unused_gin_index.sql (1.07ms)19912026/09/10 17:38:53 OK 20251218171726_add_pins.sql (1.82ms)19922026/09/10 17:38:53 OK 20260628120000_add_object_size_and_stats.sql (1.94ms)19932026/09/10 17:38:53 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-config19942026/09/10 17:38:53 OK 20260905000000_add_claims.sql (3.08ms)19952026/09/10 17:38:53 goose: successfully migrated database to version: 2026090500000019962026/09/10 17:38:53 OK 1_commit_pending_closure.sql (1.46ms)19972026/09/10 17:38:53 OK 2_object_stats_trigger.sql (637.16µs)19982026/09/10 17:38:53 goose: up to current file version: 219992026/09/10 17:38:53 WARN mTLS auth: subject not in bound subjects subject="CN=reader"20002026/09/10 17:38:53 WARN mTLS auth: subject not in bound subjects subject="CN=reader"2001--- PASS: TestService_NativeMTLS (0.36s)20022026/09/10 17:38:53 INFO Received complete multipart upload request method=POST path=/api/multipart/complete2003=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token2004=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token2005=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected2006=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected2007=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected2008=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected2009=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2010=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2011=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token2012=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected2013=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected20142026/09/10 17:38:53 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]2015=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured20162026/09/10 17:38:53 INFO OIDC auth successful provider=test scopes=[write]20172026/09/10 17:38:53 WARN Authentication failed token_preview=eyJhbGciOi...88lQnTs4HQ token_length=702 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]2018--- PASS: TestService_AuthMiddleware_OIDC (0.36s)2019 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)2020 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)2021 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)2022 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)20232026/09/10 17:38:53 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=YzA4YzgyZjMtZjc1OS00ZDlmLWIzZTUtMWIyNzkyMjYzODE5LjA2OWExNmEwLWJiZjktNDJjNi04YzgzLTBiMTViNWQ2YjQzZXgxNzg5MDYxOTMyNTM2Mjk3Njcz parts=122024--- PASS: TestRedundantMultipartUpload (0.97s)20252026/09/10 17:38:53 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=020262026/09/10 17:38:53 INFO Vacuumed table table=pending_closures20272026/09/10 17:38:53 INFO Vacuumed table table=pending_objects20282026/09/10 17:38:53 INFO Vacuumed table table=multipart_uploads20292026/09/10 17:38:53 INFO Vacuumed table table=closures20302026/09/10 17:38:53 INFO Vacuumed table table=objects2031--- PASS: TestResurrectedObjectNotDeleted (0.37s)20322026/09/10 17:38:53 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=214.076116ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2033--- PASS: TestCacheStatsHandler (0.37s)2034--- PASS: TestMetricsInventory (0.40s)2035=== NAME TestOrphanedObjectsGC2036 orphaned_objects_gc_test.go:290: GC Test Summary:2037 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A2038 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B2039 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)2040 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)2041 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects2042--- PASS: TestOrphanedObjectsGC (0.61s)2043=== NAME TestNARDeduplicationMetadataUploadBug2044 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug1939810954/001/store/n4lx8q1ahxx1frca7sjrx601lviccwlc-file1.txt2045=== NAME TestClientMultipleUploads2046 client_integration_test.go:339: Created store path 0: /build/TestClientMultipleUploads1611282427/001/store/4191rqmna0qda41hvpxbwn08zayrwn1p-test-file-0.txt2047=== NAME TestPinProtectsFromGC2048 client_integration_test.go:648: Pinned store path: /build/TestPinProtectsFromGC1418851811/001/store/zgd0z3blknbgas32qx9n4yhz5ms0d0nw-pinned-file.txt2049 client_integration_test.go:649: Unpinned store path: /build/TestPinProtectsFromGC1418851811/001/store/x3ix9a882ywg5k0nl4lci80dy5r2nrvd-unpinned-file.txt20502026/09/10 17:38:53 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"2051=== NAME TestClientMultipleUploads2052 client_integration_test.go:339: Created store path 1: /build/TestClientMultipleUploads1611282427/001/store/gg9sqjbrgmdxdghikfdy7d29w0357ykw-test-file-1.txt20532026/09/10 17:38:53 INFO Received uploads request method=POST path=/api/pending_closures20542026/09/10 17:38:53 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)20552026/09/10 17:38:53 INFO Uploading n4lx8q1ahxx1frca7sjrx601lviccwlc-file1.txt (160B)20562026/09/10 17:38:53 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"2057=== NAME TestClientWithDependencies2058 client_integration_test.go:594: Built derivation: /build/TestClientWithDependencies3767841437/001/store/gqp02ms0wjkr4pdgs95dmyfimlmr0lr5-test-script20592026/09/10 17:38:53 WARN Failed to register uploaded object key=n4lx8q1ahxx1frca7sjrx601lviccwlc.ls error="server returned 404: 404 page not found\n"20602026/09/10 17:38:53 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign20612026/09/10 17:38:53 INFO Signed narinfos id=1 count=120622026/09/10 17:38:53 INFO Uploading 1 narinfos2063=== NAME TestClientMultipleUploads2064 client_integration_test.go:339: Created store path 2: /build/TestClientMultipleUploads1611282427/001/store/w8xq4k2vy547gwng6jlb31n7z0r8wgqn-test-file-2.txt20652026/09/10 17:38:53 WARN Failed to register uploaded object key=n4lx8q1ahxx1frca7sjrx601lviccwlc.narinfo error="server returned 404: 404 page not found\n"20662026/09/10 17:38:53 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete20672026/09/10 17:38:53 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"20682026/09/10 17:38:53 INFO Completed upload id=120692026/09/10 17:38:53 INFO Upload complete. (89ms)2070=== NAME TestNARDeduplicationMetadataUploadBug2071 metadata_upload_test.go:54: Retrieved narinfo from S3:2072 StorePath: /build/TestNARDeduplicationMetadataUploadBug1939810954/001/store/n4lx8q1ahxx1frca7sjrx601lviccwlc-file1.txt2073 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst2074 Compression: zstd2075 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf2076 NarSize: 1602077 References: 2078 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf2079 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)2080 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):2081 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}2082=== NAME TestClientWithDependencies2083 client_integration_test.go:596: Found 1 dependencies (including self)20842026/09/10 17:38:53 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=368.630098ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20852026/09/10 17:38:53 INFO Received uploads request method=POST path=/api/pending_closures20862026/09/10 17:38:53 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)20872026/09/10 17:38:53 INFO Uploading zgd0z3blknbgas32qx9n4yhz5ms0d0nw-pinned-file.txt (128B)2088=== NAME TestNARDeduplicationMetadataUploadBug2089 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug1939810954/001/store/ggsl518myc12z4fn37wpm23qm15dc8iq-file2.txt20902026/09/10 17:38:53 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"20912026/09/10 17:38:53 WARN Failed to register uploaded object key=zgd0z3blknbgas32qx9n4yhz5ms0d0nw.ls error="server returned 404: 404 page not found\n"20922026/09/10 17:38:53 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign20932026/09/10 17:38:53 INFO Signed narinfos id=1 count=120942026/09/10 17:38:53 INFO Uploading 1 narinfos20952026/09/10 17:38:53 WARN Failed to register uploaded object key=zgd0z3blknbgas32qx9n4yhz5ms0d0nw.narinfo error="server returned 404: 404 page not found\n"20962026/09/10 17:38:53 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete20972026/09/10 17:38:53 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"20982026/09/10 17:38:53 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"20992026/09/10 17:38:53 INFO Completed upload id=121002026/09/10 17:38:53 INFO Upload complete. (91ms)21012026/09/10 17:38:53 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"21022026/09/10 17:38:53 INFO Received uploads request method=POST path=/api/pending_closures21032026/09/10 17:38:53 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)21042026/09/10 17:38:53 INFO Uploading gqp02ms0wjkr4pdgs95dmyfimlmr0lr5-test-script (136B)21052026/09/10 17:38:53 WARN Failed to register uploaded object key=log/0nxpk1jwv8wmiw1jpr3696zap2pvcfr6-test-script.drv error="server returned 404: 404 page not found\n"21062026/09/10 17:38:53 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"21072026/09/10 17:38:53 WARN Failed to register uploaded object key=gqp02ms0wjkr4pdgs95dmyfimlmr0lr5.ls error="server returned 404: 404 page not found\n"21082026/09/10 17:38:53 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign21092026/09/10 17:38:53 INFO Signed narinfos id=1 count=121102026/09/10 17:38:53 INFO Uploading 1 narinfos21112026/09/10 17:38:53 INFO Received uploads request method=POST path=/api/pending_closures21122026/09/10 17:38:53 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"21132026/09/10 17:38:53 INFO Received uploads request method=POST path=/api/pending_closures21142026/09/10 17:38:53 WARN Failed to register uploaded object key=gqp02ms0wjkr4pdgs95dmyfimlmr0lr5.narinfo error="server returned 404: 404 page not found\n"21152026/09/10 17:38:53 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete21162026/09/10 17:38:53 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"21172026/09/10 17:38:53 INFO Received uploads request method=POST path=/api/pending_closures21182026/09/10 17:38:53 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)21192026/09/10 17:38:53 INFO Uploading w8xq4k2vy547gwng6jlb31n7z0r8wgqn-test-file-2.txt (160B)21202026/09/10 17:38:53 INFO Uploading 4191rqmna0qda41hvpxbwn08zayrwn1p-test-file-0.txt (160B)21212026/09/10 17:38:53 INFO Uploading gg9sqjbrgmdxdghikfdy7d29w0357ykw-test-file-1.txt (160B)21222026/09/10 17:38:53 INFO Completed upload id=121232026/09/10 17:38:53 INFO Upload complete. (48ms)2124=== NAME TestClientWithDependencies2125 client_integration_test.go:598: Skipping nix copy test - isolated store (/build/TestClientWithDependencies3767841437/001/store) requires matching store prefix21262026/09/10 17:38:53 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"21272026/09/10 17:38:53 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"21282026/09/10 17:38:53 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"21292026/09/10 17:38:53 WARN Failed to register uploaded object key=4191rqmna0qda41hvpxbwn08zayrwn1p.ls error="server returned 404: 404 page not found\n"21302026/09/10 17:38:53 WARN Failed to register uploaded object key=w8xq4k2vy547gwng6jlb31n7z0r8wgqn.ls error="server returned 404: 404 page not found\n"21312026/09/10 17:38:53 WARN Failed to register uploaded object key=gg9sqjbrgmdxdghikfdy7d29w0357ykw.ls error="server returned 404: 404 page not found\n"2132--- PASS: TestClientWithDependencies (0.59s)21332026/09/10 17:38:53 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign21342026/09/10 17:38:53 INFO Signed narinfos id=1 count=121352026/09/10 17:38:53 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign21362026/09/10 17:38:53 INFO Signed narinfos id=2 count=121372026/09/10 17:38:53 INFO Received sign narinfos request method=POST path=/api/pending_closures/3/sign21382026/09/10 17:38:53 INFO Signed narinfos id=3 count=121392026/09/10 17:38:53 INFO Uploading 3 narinfos21402026/09/10 17:38:53 WARN Failed to register uploaded object key=4191rqmna0qda41hvpxbwn08zayrwn1p.narinfo error="server returned 404: 404 page not found\n"21412026/09/10 17:38:53 WARN Failed to register uploaded object key=gg9sqjbrgmdxdghikfdy7d29w0357ykw.narinfo error="server returned 404: 404 page not found\n"21422026/09/10 17:38:53 WARN Failed to register uploaded object key=w8xq4k2vy547gwng6jlb31n7z0r8wgqn.narinfo error="server returned 404: 404 page not found\n"21432026/09/10 17:38:53 INFO Received complete upload request method=POST path=/api/pending_closures/3/complete21442026/09/10 17:38:53 INFO Completed upload id=321452026/09/10 17:38:53 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete21462026/09/10 17:38:53 INFO Completed upload id=121472026/09/10 17:38:53 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete21482026/09/10 17:38:53 INFO Completed upload id=221492026/09/10 17:38:53 INFO Upload complete. (95ms)2150=== NAME TestClientMultipleUploads2151 client_integration_test.go:350: Uploaded 3 paths in 127.74025ms21522026/09/10 17:38:53 INFO Received uploads request method=POST path=/api/pending_closures21532026/09/10 17:38:53 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)21542026/09/10 17:38:53 WARN Failed to register uploaded object key=ggsl518myc12z4fn37wpm23qm15dc8iq.ls error="server returned 404: 404 page not found\n"21552026/09/10 17:38:53 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign21562026/09/10 17:38:53 INFO Signed narinfos id=2 count=121572026/09/10 17:38:53 INFO Uploading 1 narinfos2158--- PASS: TestClientMultipleUploads (0.60s)21592026/09/10 17:38:53 WARN Failed to register uploaded object key=ggsl518myc12z4fn37wpm23qm15dc8iq.narinfo error="server returned 404: 404 page not found\n"21602026/09/10 17:38:53 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete21612026/09/10 17:38:53 INFO Completed upload id=221622026/09/10 17:38:53 INFO Upload complete. (68ms)2163=== NAME TestNARDeduplicationMetadataUploadBug2164 metadata_upload_test.go:76: Retrieved narinfo from S3:2165 StorePath: /build/TestNARDeduplicationMetadataUploadBug1939810954/001/store/ggsl518myc12z4fn37wpm23qm15dc8iq-file2.txt2166 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst2167 Compression: zstd2168 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf2169 NarSize: 1602170 References: 2171 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf2172 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)2173 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):2174 {"version":1,"root":{"type":"regular","size":44}}21752026/09/10 17:38:53 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"2176--- PASS: TestNARDeduplicationMetadataUploadBug (0.66s)2177--- PASS: TestUploadHandlersRejectOversizedBody (0.19s)2178 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.04s)2179 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.07s)2180 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.60s)21812026/09/10 17:38:53 INFO Received uploads request method=POST path=/api/pending_closures21822026/09/10 17:38:53 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)21832026/09/10 17:38:53 INFO Uploading x3ix9a882ywg5k0nl4lci80dy5r2nrvd-unpinned-file.txt (128B)21842026/09/10 17:38:53 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"21852026/09/10 17:38:53 WARN Failed to register uploaded object key=x3ix9a882ywg5k0nl4lci80dy5r2nrvd.ls error="server returned 404: 404 page not found\n"21862026/09/10 17:38:53 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign21872026/09/10 17:38:53 INFO Signed narinfos id=2 count=121882026/09/10 17:38:53 INFO Uploading 1 narinfos21892026/09/10 17:38:53 WARN Failed to register uploaded object key=x3ix9a882ywg5k0nl4lci80dy5r2nrvd.narinfo error="server returned 404: 404 page not found\n"21902026/09/10 17:38:53 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete21912026/09/10 17:38:53 INFO Completed upload id=221922026/09/10 17:38:53 INFO Upload complete. (177ms)21932026/09/10 17:38:53 INFO Received create pin request method=POST path=/api/pins/myapp21942026/09/10 17:38:53 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC1418851811/001/store/zgd0z3blknbgas32qx9n4yhz5ms0d0nw-pinned-file.txt narinfo_key=zgd0z3blknbgas32qx9n4yhz5ms0d0nw.narinfo21952026/09/10 17:38:53 INFO Starting cleanup of old closures method=DELETE path=/api/closures21962026/09/10 17:38:53 INFO Garbage collection started21972026/09/10 17:38:53 INFO Aborted multipart uploads count=021982026/09/10 17:38:53 WARN Force mode enabled - objects will be deleted immediately without grace period21992026/09/10 17:38:53 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=733.320216ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2200--- PASS: TestClaim_StreamsThroughServer (2.19s)22012026/09/10 17:38:54 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=02202=== NAME TestClientIntegration2203 client_integration_test.go:304: Objects in database after GC:2204 client_integration_test.go:304: Successfully deleted all objects with GC --force2205--- PASS: TestClientIntegration (2.60s)22062026/09/10 17:38:54 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.629634216s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2207=== NAME TestOrphanedObjectsGCStressTest2208 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains22092026/09/10 17:38:54 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=022102026/09/10 17:38:54 INFO Vacuumed table table=pending_closures22112026/09/10 17:38:54 INFO Vacuumed table table=pending_objects22122026/09/10 17:38:54 INFO Vacuumed table table=multipart_uploads22132026/09/10 17:38:54 INFO Vacuumed table table=closures22142026/09/10 17:38:54 INFO Vacuumed table table=objects2215 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion2216--- PASS: TestClaim_HolderDisconnectKeepsClaim (3.12s)2217=== NAME TestOrphanedObjectsGCStressTest2218 orphaned_objects_gc_test.go:509: Stress test completed successfully:2219 orphaned_objects_gc_test.go:510: - Active objects preserved: 202220 orphaned_objects_gc_test.go:511: - Objects deleted: 2102221 orphaned_objects_gc_test.go:512: - Total GC'd: 2102222--- PASS: TestOrphanedObjectsGCStressTest (2.23s)22232026/09/10 17:38:55 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=02224=== NAME TestPinProtectsFromGC2225 client_integration_test.go:711: Pin successfully protected closure from garbage collection2226--- PASS: TestPinProtectsFromGC (2.85s)22272026/09/10 17:38:56 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"22282026/09/10 17:38:56 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_closures22292026/09/10 17:38:56 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=204.903708ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22302026/09/10 17:38:56 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=364.986221ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22312026/09/10 17:38:56 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=763.1302ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22322026/09/10 17:38:57 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.728358973s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22332026/09/10 17:38:58 WARN Rate limiter enabled after throttle name=s3-test rate=522342026/09/10 17:38:58 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."2235=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle2236 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=102237 throttle_test.go:215: Rate limiter: enabled=true, rate=5.002238--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (7.01s)2239--- PASS: TestClientErrorHandling (0.01s)2240 --- PASS: TestClientErrorHandling/InvalidStorePath (0.38s)2241 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.49s)2242 --- PASS: TestClientErrorHandling/ServerNotAvailable (6.36s)2243PASS2244{"timestamp":"2026-09-10T17:38:59.275884412Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:55108","error_kind":"io_error","error":"Cancelled","result":"transport_error","target":"rustfs::server::http","filename":"rustfs/src/server/http.rs","line_number":1866,"threadName":"rustfs-worker","threadId":"ThreadId(757)"}22452026-09-10 17:38:59.492 UTC [127] LOG: received smart shutdown request22462026-09-10 17:38:59.496 UTC [127] LOG: background worker "logical replication launcher" (PID 137) exited with exit code 122472026-09-10 17:38:59.507 UTC [132] LOG: shutting down22482026-09-10 17:38:59.508 UTC [132] LOG: checkpoint starting: shutdown immediate22492026-09-10 17:39:00.609 UTC [132] LOG: checkpoint complete: wrote 11490 buffers (70.1%), wrote 3 SLRU buffers; 0 WAL file(s) added, 0 removed, 17 recycled; write=0.214 s, sync=0.869 s, total=1.102 s; sync files=21000, longest=0.003 s, average=0.001 s; distance=282891 kB, estimate=282891 kB; lsn=0/12BA8BE0, redo lsn=0/12BA8BE022502026-09-10 17:39:00.699 UTC [127] LOG: database system is shut down2251Running OIDC tests...2252=== RUN TestGlobMatch2253=== PAUSE TestGlobMatch2254=== RUN TestAudienceForIssuer2255=== PAUSE TestAudienceForIssuer2256=== RUN TestValidateToken_ValidToken2257=== PAUSE TestValidateToken_ValidToken2258=== RUN TestValidateToken_WrongAudience2259=== PAUSE TestValidateToken_WrongAudience2260=== RUN TestValidateToken_Expired2261=== PAUSE TestValidateToken_Expired2262=== RUN TestValidateToken_BoundClaimsMismatch2263=== PAUSE TestValidateToken_BoundClaimsMismatch2264=== RUN TestValidateToken_BoundSubjectMismatch2265=== PAUSE TestValidateToken_BoundSubjectMismatch2266=== RUN TestValidateToken_MultipleProviders2267=== PAUSE TestValidateToken_MultipleProviders2268=== RUN TestValidateToken_NoMatchingProvider2269=== PAUSE TestValidateToken_NoMatchingProvider2270=== RUN TestValidateToken_KubernetesServiceAccount2271=== PAUSE TestValidateToken_KubernetesServiceAccount2272=== RUN TestNewValidator_KubernetesRequiresCA2273=== PAUSE TestNewValidator_KubernetesRequiresCA2274=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2275=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2276=== RUN TestScopes_LegacyProviderDefaultsToWrite2277=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2278=== RUN TestScopes_Rules2279=== PAUSE TestScopes_Rules2280=== RUN TestScopes_ConfigValidation2281=== PAUSE TestScopes_ConfigValidation2282=== CONT TestGlobMatch2283=== CONT TestValidateToken_NoMatchingProvider2284=== CONT TestScopes_LegacyProviderDefaultsToWrite2285=== CONT TestScopes_ConfigValidation2286=== RUN TestGlobMatch/foo_foo2287=== PAUSE TestGlobMatch/foo_foo2288=== RUN TestGlobMatch/foo_bar2289=== PAUSE TestGlobMatch/foo_bar2290=== CONT TestValidateToken_MultipleProviders2291=== CONT TestValidateToken_BoundSubjectMismatch2292=== CONT TestValidateToken_BoundClaimsMismatch2293=== CONT TestValidateToken_Expired2294=== CONT TestValidateToken_WrongAudience2295=== CONT TestValidateToken_ValidToken2296=== CONT TestAudienceForIssuer2297--- PASS: TestAudienceForIssuer (0.00s)2298=== CONT TestNewValidator_KubernetesRequiresCA2299=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2300=== CONT TestValidateToken_KubernetesServiceAccount2301=== CONT TestScopes_Rules2302=== RUN TestGlobMatch/*_2303=== PAUSE TestGlobMatch/*_2304=== RUN TestGlobMatch/*_anything2305=== PAUSE TestGlobMatch/*_anything2306=== RUN TestGlobMatch/foo*_foo2307=== PAUSE TestGlobMatch/foo*_foo2308=== RUN TestGlobMatch/foo*_foobar2309=== PAUSE TestGlobMatch/foo*_foobar2310=== RUN TestGlobMatch/foo*_bar2311=== PAUSE TestGlobMatch/foo*_bar2312=== RUN TestGlobMatch/*bar_bar2313=== PAUSE TestGlobMatch/*bar_bar2314=== RUN TestGlobMatch/*bar_foobar2315=== PAUSE TestGlobMatch/*bar_foobar2316=== RUN TestGlobMatch/*bar_foo2317=== PAUSE TestGlobMatch/*bar_foo2318=== RUN TestGlobMatch/foo*bar_foobar2319=== PAUSE TestGlobMatch/foo*bar_foobar2320=== RUN TestGlobMatch/foo*bar_foo123bar2321=== PAUSE TestGlobMatch/foo*bar_foo123bar2322=== RUN TestGlobMatch/foo*bar_foobarbaz2323--- PASS: TestScopes_ConfigValidation (0.00s)2324=== PAUSE TestGlobMatch/foo*bar_foobarbaz2325=== RUN TestGlobMatch/*/*_foo/bar2326=== PAUSE TestGlobMatch/*/*_foo/bar2327=== RUN TestGlobMatch/*/*_foo2328=== PAUSE TestGlobMatch/*/*_foo2329=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2330=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2331=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02332=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02333=== RUN TestGlobMatch/refs/*/main_refs/heads/main2334=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2335=== RUN TestGlobMatch/fo?_foo2336=== PAUSE TestGlobMatch/fo?_foo2337=== RUN TestGlobMatch/fo?_fo2338=== PAUSE TestGlobMatch/fo?_fo2339=== RUN TestGlobMatch/fo?_fooo2340=== PAUSE TestGlobMatch/fo?_fooo2341=== RUN TestGlobMatch/?oo_foo2342=== PAUSE TestGlobMatch/?oo_foo2343=== RUN TestGlobMatch/?oo_boo2344=== PAUSE TestGlobMatch/?oo_boo2345=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2346=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main23472026/09/10 17:39:02 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:35133/oidc23482026/09/10 17:39:02 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:36289/oidc2349=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2350=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main23512026/09/10 17:39:02 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:38921/oidc2352=== CONT TestGlobMatch/*/*_foo/bar23532026/09/10 17:39:02 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:40389/oidc2354=== CONT TestGlobMatch/foo*bar_foobar2355=== CONT TestGlobMatch/*bar_bar23562026/09/10 17:39:02 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:42157/oidc2357=== CONT TestGlobMatch/refs/heads/*_refs/heads/main23582026/09/10 17:39:02 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:42891/oidc2359=== CONT TestGlobMatch/foo*bar_foobarbaz23602026/09/10 17:39:02 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:35533/oidc2361=== CONT TestGlobMatch/fo?_fo23622026/09/10 17:39:02 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:42097/oidc2363=== CONT TestGlobMatch/*bar_foo2364=== CONT TestGlobMatch/foo_foo2365=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2366=== CONT TestGlobMatch/*bar_foobar2367=== CONT TestGlobMatch/fo?_foo2368=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2369=== CONT TestGlobMatch/fo?_fooo2370=== CONT TestGlobMatch/?oo_foo2371=== CONT TestGlobMatch/foo*bar_foo123bar2372=== CONT TestGlobMatch/*_anything2373=== CONT TestGlobMatch/*_2374=== CONT TestGlobMatch/foo_bar2375=== CONT TestGlobMatch/foo*_foo2376=== CONT TestGlobMatch/foo*_bar23772026/09/10 17:39:02 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:46783/oidc2378=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02379=== CONT TestGlobMatch/?oo_boo2380=== CONT TestGlobMatch/foo*_foobar2381=== CONT TestGlobMatch/refs/*/main_refs/heads/main2382=== CONT TestGlobMatch/*/*_foo2383--- PASS: TestGlobMatch (0.01s)2384 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2385 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2386 --- PASS: TestGlobMatch/*bar_bar (0.00s)2387 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2388 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2389 --- PASS: TestGlobMatch/fo?_fo (0.00s)2390 --- PASS: TestGlobMatch/*bar_foo (0.00s)2391 --- PASS: TestGlobMatch/foo_foo (0.00s)2392 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2393 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2394 --- PASS: TestGlobMatch/fo?_foo (0.00s)2395 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2396 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2397 --- PASS: TestGlobMatch/?oo_foo (0.00s)2398 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2399 --- PASS: TestGlobMatch/*_anything (0.00s)2400 --- PASS: TestGlobMatch/*_ (0.00s)2401 --- PASS: TestGlobMatch/foo_bar (0.00s)2402 --- PASS: TestGlobMatch/foo*_foo (0.00s)2403 --- PASS: TestGlobMatch/foo*_bar (0.00s)2404 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2405 --- PASS: TestGlobMatch/?oo_boo (0.00s)2406 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2407 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2408 --- PASS: TestGlobMatch/*/*_foo (0.00s)24092026/09/10 17:39:02 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:42189/oidc24102026/09/10 17:39:02 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC1232411--- PASS: TestValidateToken_ValidToken (0.01s)2412--- PASS: TestValidateToken_BoundSubjectMismatch (0.01s)2413--- PASS: TestValidateToken_BoundClaimsMismatch (0.01s)2414--- PASS: TestValidateToken_Expired (0.01s)2415--- PASS: TestValidateToken_WrongAudience (0.01s)2416--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.02s)2417--- PASS: TestValidateToken_NoMatchingProvider (0.02s)2418--- PASS: TestValidateToken_MultipleProviders (0.02s)24192026/09/10 17:39:02 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:390672420--- PASS: TestScopes_Rules (0.02s)2421--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.02s)24222026/09/10 17:39:02 http: TLS handshake error from 127.0.0.1:39578: remote error: tls: bad certificate2423--- PASS: TestNewValidator_KubernetesRequiresCA (0.02s)2424--- PASS: TestValidateToken_KubernetesServiceAccount (0.02s)2425PASS2426Running hook tests...2427=== RUN TestSendPathsEmpty2428=== PAUSE TestSendPathsEmpty2429=== RUN TestQueueEnqueueAndFetch2430=== PAUSE TestQueueEnqueueAndFetch2431=== RUN TestQueueDeduplication2432=== PAUSE TestQueueDeduplication2433=== RUN TestQueueRemove2434=== PAUSE TestQueueRemove2435=== RUN TestQueueFetchBatchLimit2436=== PAUSE TestQueueFetchBatchLimit2437=== RUN TestQueueRetryMovesToBack2438=== PAUSE TestQueueRetryMovesToBack2439=== RUN TestQueueFetchRemoveLifecycle2440=== PAUSE TestQueueFetchRemoveLifecycle2441=== RUN TestQueueConcurrentWriters2442=== PAUSE TestQueueConcurrentWriters2443=== RUN TestQueueRemoveLargeClosure2444=== PAUSE TestQueueRemoveLargeClosure2445=== RUN TestServerClientIntegration2446=== PAUSE TestServerClientIntegration2447=== RUN TestServerQueueError2448=== PAUSE TestServerQueueError2449=== RUN TestGetListenerSocketActivation2450 server_test.go:210: === RUN TestGetListenerSocketActivation2451 --- PASS: TestGetListenerSocketActivation (0.00s)2452 PASS2453 2454--- PASS: TestGetListenerSocketActivation (0.01s)2455=== RUN TestDrainIsolatesPoisonPath2456=== PAUSE TestDrainIsolatesPoisonPath2457=== RUN TestRunNotBlockedByPoisonHead2458=== PAUSE TestRunNotBlockedByPoisonHead2459=== RUN TestDrainGivesUpWhenServerDown2460=== PAUSE TestDrainGivesUpWhenServerDown2461=== RUN TestFailedPathPrunedByLaterClosure2462=== PAUSE TestFailedPathPrunedByLaterClosure2463=== RUN TestWorkerUploadsAndRemoves2464=== PAUSE TestWorkerUploadsAndRemoves2465=== RUN TestWorkerSkipsGCdPaths2466=== PAUSE TestWorkerSkipsGCdPaths2467=== RUN TestWorkerPrunesClosureDeps2468=== PAUSE TestWorkerPrunesClosureDeps2469=== RUN TestDrainTimeout2470=== PAUSE TestDrainTimeout2471=== CONT TestSendPathsEmpty2472=== CONT TestServerQueueError2473--- PASS: TestSendPathsEmpty (0.00s)2474=== CONT TestServerClientIntegration2475=== CONT TestQueueRemoveLargeClosure2476=== CONT TestQueueConcurrentWriters2477=== CONT TestQueueFetchRemoveLifecycle2478=== CONT TestQueueRetryMovesToBack2479=== CONT TestQueueFetchBatchLimit2480=== CONT TestQueueRemove2481=== CONT TestQueueDeduplication24822026/09/10 17:39:02 ERROR Failed to queue paths error="permission denied" count=12483=== CONT TestQueueEnqueueAndFetch2484=== CONT TestWorkerPrunesClosureDeps2485=== CONT TestDrainTimeout2486=== CONT TestDrainGivesUpWhenServerDown2487=== CONT TestWorkerUploadsAndRemoves2488=== CONT TestFailedPathPrunedByLaterClosure2489=== CONT TestWorkerSkipsGCdPaths2490=== CONT TestRunNotBlockedByPoisonHead2491=== CONT TestDrainIsolatesPoisonPath2492--- PASS: TestServerQueueError (0.00s)2493--- PASS: TestServerClientIntegration (0.00s)24942026/09/10 17:39:02 INFO Upload queue status pending=224952026/09/10 17:39:02 INFO Uploading batch count=124962026/09/10 17:39:02 ERROR Upload failed error="upload failed" count=124972026/09/10 17:39:02 INFO Uploading batch count=124982026/09/10 17:39:02 INFO Upload queue status pending=324992026/09/10 17:39:02 INFO Uploading batch count=125002026/09/10 17:39:02 ERROR Upload failed error="upload failed" count=125012026/09/10 17:39:02 INFO Upload queue status pending=225022026/09/10 17:39:02 INFO Uploading batch count=425032026/09/10 17:39:02 ERROR Upload failed error="upload failed" count=425042026/09/10 17:39:02 INFO Uploading batch count=225052026/09/10 17:39:02 INFO Uploading batch count=22506--- PASS: TestQueueDeduplication (0.02s)2507--- PASS: TestQueueEnqueueAndFetch (0.02s)25082026/09/10 17:39:02 INFO Upload queue status pending=225092026/09/10 17:39:02 INFO Uploading batch count=22510--- PASS: TestQueueFetchBatchLimit (0.02s)25112026/09/10 17:39:02 ERROR Upload failed error="upload failed" count=225122026/09/10 17:39:02 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3455002165/002/a25132026/09/10 17:39:02 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerSkipsGCdPaths2378081997/002/nonexistent25142026/09/10 17:39:02 INFO Uploading batch count=12515--- PASS: TestQueueRemove (0.02s)25162026/09/10 17:39:02 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3455002165/002/b25172026/09/10 17:39:02 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainIsolatesPoisonPath2680827209/002/bbb2518--- PASS: TestQueueRetryMovesToBack (0.02s)2519--- PASS: TestQueueFetchRemoveLifecycle (0.02s)25202026/09/10 17:39:02 INFO Uploading batch count=125212026/09/10 17:39:02 INFO Uploading batch count=225222026/09/10 17:39:02 ERROR Upload failed error="upload failed" count=225232026/09/10 17:39:02 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3455002165/002/c25242026/09/10 17:39:02 INFO Uploading batch count=125252026/09/10 17:39:02 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3455002165/002/d25262026/09/10 17:39:02 INFO Uploading batch count=225272026/09/10 17:39:02 ERROR Upload failed error="upload failed" count=225282026/09/10 17:39:02 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3455002165/002/e25292026/09/10 17:39:02 INFO Uploading batch count=125302026/09/10 17:39:02 ERROR Upload failed error="upload failed" count=125312026/09/10 17:39:02 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3455002165/002/f2532--- PASS: TestFailedPathPrunedByLaterClosure (0.02s)25332026/09/10 17:39:02 INFO Uploading batch count=125342026/09/10 17:39:02 ERROR Upload failed error="upload failed" count=125352026/09/10 17:39:02 ERROR Drain finished with paths left in queue remaining=1025362026/09/10 17:39:02 INFO Uploading batch count=125372026/09/10 17:39:02 ERROR Upload failed error="upload failed" count=125382026/09/10 17:39:02 ERROR Drain finished with paths left in queue remaining=12539--- PASS: TestDrainGivesUpWhenServerDown (0.02s)2540--- PASS: TestDrainIsolatesPoisonPath (0.02s)2541--- PASS: TestWorkerPrunesClosureDeps (0.03s)2542--- PASS: TestWorkerSkipsGCdPaths (0.03s)2543--- PASS: TestWorkerUploadsAndRemoves (0.03s)2544--- PASS: TestQueueRemoveLargeClosure (0.07s)25452026/09/10 17:39:02 ERROR Upload failed error="context deadline exceeded" count=225462026/09/10 17:39:02 ERROR Drain finished with paths left in queue remaining=42547--- PASS: TestDrainTimeout (0.22s)2548--- PASS: TestQueueConcurrentWriters (0.22s)25492026/09/10 17:39:03 INFO Uploading batch count=125502026/09/10 17:39:03 INFO Uploading batch count=125512026/09/10 17:39:03 INFO Uploading batch count=125522026/09/10 17:39:03 ERROR Upload failed error="upload failed" count=125532026/09/10 17:39:03 INFO Uploading batch count=125542026/09/10 17:39:03 ERROR Upload failed error="upload failed" count=125552026/09/10 17:39:03 INFO Uploading batch count=125562026/09/10 17:39:03 ERROR Upload failed error="upload failed" count=125572026/09/10 17:39:03 INFO Uploading batch count=125582026/09/10 17:39:03 ERROR Upload failed error="upload failed" count=125592026/09/10 17:39:03 ERROR Drain finished with paths left in queue remaining=12560--- PASS: TestRunNotBlockedByPoisonHead (1.03s)2561PASS