niks3-go-unit-tests
checks.x86_64-linux.go-unit-tests
· build #213
· 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 TestStreamPushRequestLine60=== PAUSE TestStreamPushRequestLine61=== RUN TestSetClientTLS62=== PAUSE TestSetClientTLS63=== RUN TestSetClientTLSDoesNotMutateDefaultTransport64=== PAUSE TestSetClientTLSDoesNotMutateDefaultTransport65=== RUN TestSetClientTLSErrors66=== PAUSE TestSetClientTLSErrors67=== RUN TestStaticToken68=== PAUSE TestStaticToken69=== RUN TestFileTokenReadsAndCaches70=== PAUSE TestFileTokenReadsAndCaches71=== RUN TestFileTokenMissing72=== PAUSE TestFileTokenMissing73=== RUN TestFileTokenEmpty74=== PAUSE TestFileTokenEmpty75=== RUN TestScriptTokenNoExpiryRerunsEveryCall76=== PAUSE TestScriptTokenNoExpiryRerunsEveryCall77=== RUN TestScriptTokenCachesUntilRefresh78=== PAUSE TestScriptTokenCachesUntilRefresh79=== RUN TestScriptTokenEmptyToken80=== PAUSE TestScriptTokenEmptyToken81=== RUN TestScriptTokenBadJSON82=== PAUSE TestScriptTokenBadJSON83=== RUN TestScriptTokenScriptFails84=== PAUSE TestScriptTokenScriptFails85=== RUN TestScriptTokenEmptyCommand86=== PAUSE TestScriptTokenEmptyCommand87=== CONT TestDoServerRequestAttachesToken88=== CONT TestShellSplit89=== CONT TestStaticToken90--- PASS: TestShellSplit (0.00s)91=== CONT TestPathInfoCACompatibility92--- PASS: TestStaticToken (0.00s)93=== CONT TestParsePathInfoJSON94=== CONT TestScriptTokenNoExpiryRerunsEveryCall95=== CONT TestFileTokenEmpty96=== CONT TestFileTokenMissing97=== CONT TestFileTokenReadsAndCaches98--- PASS: TestFileTokenMissing (0.00s)99=== CONT TestResolveStorePath100--- PASS: TestFileTokenEmpty (0.00s)101=== CONT TestPathInfoHashCompatibility102=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)103=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)104=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon105=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon106=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI107=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI108=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512109=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512110=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess111=== CONT TestScriptTokenScriptFails112=== CONT TestScriptTokenEmptyCommand113=== CONT TestScriptTokenCachesUntilRefresh114=== CONT TestScriptTokenEmptyToken115=== CONT TestStreamPushGivesUpOnDeadServer1162026/09/16 23:48:56 WARN Rate limiter enabled after throttle name=server-test rate=5117=== CONT TestSetClientTLSDoesNotMutateDefaultTransport118=== CONT TestSetClientTLS119=== CONT TestSetClientTLSErrors1202026/09/16 23:48:56 ERROR Upload failed error="connection refused" count=20121=== CONT TestStreamPushRequestLine1222026/09/16 23:48:56 ERROR Server seems unavailable, giving up on batch untried=17123=== CONT TestUploadMultipart_SupersededByPeer124=== RUN TestUploadMultipart_SupersededByPeer/exists125=== CONT TestStreamPushBatchesUnderLoad126=== CONT TestStreamPushIsolatesFailures127=== CONT TestStreamPushReportsEveryPath128=== CONT TestConvertHashToNix32129=== CONT TestShellSplitErrors130=== CONT TestDoWithRetry_BodyReplayedViaGetBody131=== CONT TestParsePathInfoJSONMultiplePaths132=== CONT TestScriptTokenBadJSON133=== RUN TestParsePathInfoJSON/Nix_format134=== RUN TestPathInfoCACompatibility/null_ca_field135--- PASS: TestFileTokenReadsAndCaches (0.00s)136=== CONT TestGetStorePathHash137=== CONT TestRateLimiterFeedback138=== CONT TestPartSizeForNAR139=== PAUSE TestUploadMultipart_SupersededByPeer/exists140=== PAUSE TestPathInfoCACompatibility/null_ca_field141--- PASS: TestScriptTokenEmptyCommand (0.00s)142--- PASS: TestResolveStorePath (0.00s)143--- PASS: TestScriptTokenScriptFails (0.00s)144--- PASS: TestShellSplitErrors (0.00s)145=== PAUSE TestParsePathInfoJSON/Nix_format146=== CONT TestEncodeNixBase32147=== RUN TestParsePathInfoJSON/Lix_format148=== RUN TestPartSizeForNAR/zero_stays_at_minimum1492026/09/16 23:48:56 ERROR Upload failed error="bad path" count=3150=== RUN TestPathInfoCACompatibility/old_string_format_-_text151=== PAUSE TestParsePathInfoJSON/Lix_format152=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths153=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths154=== RUN TestConvertHashToNix32/SRI_format_to_Nix32155=== RUN TestEncodeNixBase32/test_string_hash156=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text157--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)158=== CONT TestFilterOversizedClosures159=== RUN TestGetStorePathHash/valid_store_path160=== RUN TestFilterOversizedClosures/no_limit_keeps_everything161=== PAUSE TestGetStorePathHash/valid_store_path1622026/09/16 23:48:56 ERROR Upload failed error="stale build claim" count=1163=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything164=== CONT TestDumpPathWriterError165=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum166=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped167=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped168=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32169=== RUN TestGetStorePathHash/basename_without_hyphen_should_error170=== RUN TestFilterOversizedClosures/all_closures_skipped171=== RUN TestConvertHashToNix32/already_Nix32_format172=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error173=== CONT TestDumpPathSingleFile174=== PAUSE TestFilterOversizedClosures/all_closures_skipped175--- PASS: TestScriptTokenEmptyToken (0.01s)176--- PASS: TestDoServerRequestAttachesToken (0.01s)1772026/09/16 23:48:56 WARN Rate limiter enabled after throttle name=server-test rate=5178=== CONT TestCaseHackSuffix1792026/09/16 23:48:56 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:44661180=== RUN TestUploadMultipart_SupersededByPeer/missing181=== PAUSE TestUploadMultipart_SupersededByPeer/missing182=== RUN TestParsePathInfoJSON/empty_input183=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha5121842026/09/16 23:48:56 WARN Rate limiter backed off name=server-test rate=5185=== PAUSE TestParsePathInfoJSON/empty_input1862026/09/16 23:48:56 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:44661187=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive188=== CONT TestEncodeNixBase32WithRealHash189=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon190=== PAUSE TestEncodeNixBase32/test_string_hash191=== RUN TestPartSizeForNAR/small_stays_at_minimum192=== RUN TestRateLimiterFeedback/429_enables_limiter193=== PAUSE TestConvertHashToNix32/already_Nix32_format194=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error195=== RUN TestSetClientTLSErrors/missing_cert_file196=== CONT TestDumpPathMatchesNix197--- PASS: TestStreamPushIsolatesFailures (0.00s)198--- PASS: TestStreamPushReportsEveryPath (0.00s)199=== PAUSE TestRateLimiterFeedback/429_enables_limiter200=== RUN TestConvertHashToNix32/invalid_format201=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths202=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths203=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI204=== RUN TestParsePathInfoJSON/whitespace_only205=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped206=== CONT TestFilterOversizedClosures/all_closures_skipped207=== PAUSE TestParsePathInfoJSON/whitespace_only208=== RUN TestEncodeNixBase32/empty_input209=== PAUSE TestEncodeNixBase32/empty_input210=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)211=== RUN TestParsePathInfoJSON/invalid_JSON212--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.01s)213=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths214=== CONT TestUploadMultipart_SupersededByPeer/missing215=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error216=== PAUSE TestPartSizeForNAR/small_stays_at_minimum217=== RUN TestSetClientTLS/rejects_connection_without_client_cert218=== RUN TestRateLimiterFeedback/503_enables_limiter219=== PAUSE TestSetClientTLSErrors/missing_cert_file2202026/09/16 23:48:56 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=50221=== CONT TestFilterOversizedClosures/no_limit_keeps_everything222=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert2232026/09/16 23:48:56 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=2000224=== CONT TestEncodeNixBase32/empty_input225=== RUN TestSetClientTLSErrors/missing_key_file226=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive227=== RUN TestPathInfoCACompatibility/new_structured_format_-_text228=== CONT TestUploadMultipart_SupersededByPeer/exists229--- PASS: TestEncodeNixBase32WithRealHash (0.00s)230--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.01s)231=== PAUSE TestParsePathInfoJSON/invalid_JSON232=== PAUSE TestRateLimiterFeedback/503_enables_limiter233=== PAUSE TestConvertHashToNix32/invalid_format234=== CONT TestEncodeNixBase32/test_string_hash235=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths236=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA237=== CONT TestConvertHashToNix32/SRI_format_to_Nix32238=== CONT TestParsePathInfoJSON/whitespace_only239=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter240=== CONT TestParsePathInfoJSON/invalid_JSON241=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA242=== RUN TestSetClientTLS/preserves_debug_logging_transport243=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text244--- PASS: TestPathInfoHashCompatibility (0.00s)245 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)246 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)247 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)248 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)249--- PASS: TestScriptTokenBadJSON (0.01s)250--- PASS: TestScriptTokenCachesUntilRefresh (0.01s)251=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method252=== CONT TestConvertHashToNix32/invalid_format253=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum254=== CONT TestParsePathInfoJSON/Nix_format255=== PAUSE TestSetClientTLSErrors/missing_key_file256=== CONT TestConvertHashToNix32/already_Nix32_format257=== CONT TestParsePathInfoJSON/empty_input258=== RUN TestSetClientTLSErrors/missing_ca_file259=== CONT TestParsePathInfoJSON/Lix_format260=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error261=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error262=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter263--- PASS: TestParsePathInfoJSONMultiplePaths (0.01s)264 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)265 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)266--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.02s)267=== PAUSE TestSetClientTLS/preserves_debug_logging_transport268=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum269=== PAUSE TestSetClientTLSErrors/missing_ca_file270=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error271=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error272=== CONT TestGetStorePathHash/basename_without_hyphen_should_error273=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts274=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts275=== RUN TestPartSizeForNAR/1_TiB276=== PAUSE TestPartSizeForNAR/1_TiB277=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method278=== CONT TestGetStorePathHash/valid_store_path279=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter280=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter281=== CONT TestRateLimiterFeedback/429_enables_limiter282=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter283=== CONT TestRateLimiterFeedback/503_enables_limiter284=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter285=== CONT TestSetClientTLS/rejects_connection_without_client_cert286=== CONT TestSetClientTLS/preserves_debug_logging_transport2872026/09/16 23:48:56 WARN Rate limiter enabled after throttle name=server-test rate=5288=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA2892026/09/16 23:48:56 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:401632902026/09/16 23:48:56 WARN Rate limiter enabled after throttle name=server-test rate=5291=== RUN TestSetClientTLSErrors/invalid_ca_file2922026/09/16 23:48:56 WARN Rate limiter backed off name=server-test rate=5293=== PAUSE TestSetClientTLSErrors/invalid_ca_file294=== CONT TestSetClientTLSErrors/missing_cert_file2952026/09/16 23:48:56 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:42673296=== CONT TestSetClientTLSErrors/invalid_ca_file297=== CONT TestSetClientTLSErrors/missing_ca_file2982026/09/16 23:48:56 WARN Rate limiter backed off name=server-test rate=5299=== RUN TestPartSizeForNAR/5_TiB_S3_max_object300=== CONT TestSetClientTLSErrors/missing_key_file301=== CONT TestPathInfoCACompatibility/null_ca_field302=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method303=== CONT TestPathInfoCACompatibility/new_structured_format_-_text304=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive305=== CONT TestPathInfoCACompatibility/old_string_format_-_text306--- PASS: TestEncodeNixBase32 (0.01s)307 --- PASS: TestEncodeNixBase32/empty_input (0.00s)308 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)309=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object310=== RUN TestPartSizeForNAR/capped_at_5_GiB311=== PAUSE TestPartSizeForNAR/capped_at_5_GiB312--- PASS: TestFilterOversizedClosures (0.00s)313 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)314 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)315 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)316--- PASS: TestConvertHashToNix32 (0.01s)317 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)318 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)319 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)320=== CONT TestPartSizeForNAR/5_TiB_S3_max_object321=== CONT TestPartSizeForNAR/zero_stays_at_minimum322=== CONT TestPartSizeForNAR/1_TiB323=== CONT TestPartSizeForNAR/capped_at_5_GiB324=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts325=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum326=== CONT TestPartSizeForNAR/small_stays_at_minimum327--- PASS: TestParsePathInfoJSON (0.02s)328 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)329 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)330 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)331 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)332 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)333--- PASS: TestGetStorePathHash (0.01s)334 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)335 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)336 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)337 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)338--- PASS: TestRateLimiterFeedback (0.01s)339 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)340 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)341 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)342 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)343--- PASS: TestPathInfoCACompatibility (0.02s)344 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)345 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)346 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)347 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)348 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)349--- PASS: TestPartSizeForNAR (0.02s)350 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)351 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)352 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)353 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)354 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)355 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)356 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)357--- PASS: TestUploadMultipart_SupersededByPeer (0.01s)358 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)359 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)360--- PASS: TestSetClientTLSErrors (0.02s)361 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)362 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)363 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)364 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)3652026/09/16 23:48:56 http: TLS handshake error from 127.0.0.1:37940: remote error: tls: bad certificate366--- PASS: TestSetClientTLS (0.02s)367 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.00s)368 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.00s)369 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.01s)370--- PASS: TestStreamPushRequestLine (0.02s)371--- PASS: TestDumpPathWriterError (0.04s)372--- PASS: TestCaseHackSuffix (0.04s)373--- PASS: TestDumpPathSingleFile (0.04s)374--- PASS: TestDumpPathMatchesNix (0.08s)375--- PASS: TestStreamPushBatchesUnderLoad (0.10s)376--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)377PASS378Running server tests...379The files belonging to this database system will be owned by user "nixbld".380This user must also own the server process.381382The database cluster will be initialized with locale "C".383The default database encoding has accordingly been set to "SQL_ASCII".384The default text search configuration will be set to "english".385386Data page checksums are enabled.387388creating directory /build/postgres2827835688/data ... ok389creating subdirectories ... ok390selecting dynamic shared memory implementation ... posix391selecting default "max_connections" ... 100392selecting default "shared_buffers" ... 128MB393selecting default time zone ... UTC394creating configuration files ... ok395running bootstrap script ... ok396performing post-bootstrap initialization ... ok397syncing data to disk ... ok398399initdb: warning: enabling "trust" authentication for local connections400initdb: 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.401402Success. You can now start the database server using:403404 pg_ctl -D /build/postgres2827835688/data -l logfile start405406/build/postgres2827835688:5432 - no response4072026-09-16 23:48:58.598 UTC [129] LOG: starting PostgreSQL 18.6 on x86_64-pc-linux-gnu, compiled by clang version 21.1.8, 64-bit4082026-09-16 23:48:58.598 UTC [129] LOG: listening on Unix socket "/build/postgres2827835688/.s.PGSQL.5432"4092026-09-16 23:48:58.603 UTC [136] LOG: database system was shut down at 2026-09-16 23:48:58 UTC4102026-09-16 23:48:58.607 UTC [129] LOG: database system is ready to accept connections411/build/postgres2827835688:5432 - accepting connections412=== RUN TestService_AuthMiddleware413=== PAUSE TestService_AuthMiddleware414=== RUN TestService_AuthMiddleware_MTLSProxyHeader415=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader416=== RUN TestService_AuthMiddleware_MTLSBoundSubjects417=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects418=== RUN TestService_ReadAuthMiddleware419=== PAUSE TestService_ReadAuthMiddleware420=== RUN TestService_AuthMiddleware_OIDC421=== PAUSE TestService_AuthMiddleware_OIDC422=== RUN TestService_RequireScope_OIDC423=== PAUSE TestService_RequireScope_OIDC424=== RUN TestService_ReadScope_PublicByDefault425=== PAUSE TestService_ReadScope_PublicByDefault426=== RUN TestCacheConfigHandler427=== PAUSE TestCacheConfigHandler428=== RUN TestCacheStatsHandler429=== PAUSE TestCacheStatsHandler430=== RUN TestClaim_BuildWaitComplete431=== PAUSE TestClaim_BuildWaitComplete432=== RUN TestClaim_GCMarkedOutputCountsAsAbsent433=== PAUSE TestClaim_GCMarkedOutputCountsAsAbsent434=== RUN TestClaim_TooManyStreams435=== PAUSE TestClaim_TooManyStreams436=== RUN TestClaim_HolderDisconnectKeepsClaim437=== PAUSE TestClaim_HolderDisconnectKeepsClaim438=== RUN TestClaim_FailWakesWaitersButIsNotRemembered439=== PAUSE TestClaim_FailWakesWaitersButIsNotRemembered440=== RUN TestClaim_FailWithoutKindReleases441=== PAUSE TestClaim_FailWithoutKindReleases442=== RUN TestClaim_StaleHeartbeatStolen443=== PAUSE TestClaim_StaleHeartbeatStolen444=== RUN TestClaim_TwoInstances445=== PAUSE TestClaim_TwoInstances446=== RUN TestClaim_InputsTouched447=== PAUSE TestClaim_InputsTouched448=== RUN TestClaim_StreamsThroughServer449=== PAUSE TestClaim_StreamsThroughServer450=== RUN TestPresent451=== PAUSE TestPresent452=== RUN TestClientCADerivations453=== PAUSE TestClientCADerivations454=== RUN TestClientErrorHandling455=== PAUSE TestClientErrorHandling456=== RUN TestClientIntegration457=== PAUSE TestClientIntegration458=== RUN TestClientMultipleUploads459=== PAUSE TestClientMultipleUploads460=== RUN TestClientWithDependencies461=== PAUSE TestClientWithDependencies462=== RUN TestPinProtectsFromGC463=== PAUSE TestPinProtectsFromGC464=== RUN TestResolveDBConnectionString465=== PAUSE TestResolveDBConnectionString466=== RUN TestGCAdvisoryLockBlocksConcurrentRun4672026-09-16 23:48:59.006 UTC [564] ERROR: relation "goose_db_version" does not exist at character 364682026-09-16 23:48:59.006 UTC [564] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC4692026/09/16 23:48:59 OK 20241026095416_initial_model.sql (6.68ms)4702026/09/16 23:48:59 OK 20251210153512_drop_unused_gin_index.sql (972.43µs)4712026/09/16 23:48:59 OK 20251218171726_add_pins.sql (2.37ms)4722026/09/16 23:48:59 OK 20260628120000_add_object_size_and_stats.sql (1.77ms)4732026/09/16 23:48:59 OK 20260905000000_add_claims.sql (2ms)4742026/09/16 23:48:59 goose: successfully migrated database to version: 202609050000004752026/09/16 23:48:59 OK 1_commit_pending_closure.sql (1.99ms)4762026/09/16 23:48:59 OK 2_object_stats_trigger.sql (529.82µs)4772026/09/16 23:48:59 goose: up to current file version: 2478--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.15s)479=== RUN TestGCBugBareHashReferences480=== PAUSE TestGCBugBareHashReferences481=== RUN TestGCMetrics482=== PAUSE TestGCMetrics483=== RUN TestGCTaskStore_StartNew484=== PAUSE TestGCTaskStore_StartNew485=== RUN TestGCTaskStore_DeduplicateSameParams486=== PAUSE TestGCTaskStore_DeduplicateSameParams487=== RUN TestGCTaskStore_ConflictDifferentParams488=== PAUSE TestGCTaskStore_ConflictDifferentParams489=== RUN TestGCTaskStore_GetEmpty490=== PAUSE TestGCTaskStore_GetEmpty491=== RUN TestGCTaskStore_GetReturnsLatest492=== PAUSE TestGCTaskStore_GetReturnsLatest493=== RUN TestGCTaskStore_CompletedAllowsNewTask494=== PAUSE TestGCTaskStore_CompletedAllowsNewTask495=== RUN TestGCTaskStore_PhaseUpdates496=== PAUSE TestGCTaskStore_PhaseUpdates497=== RUN TestGCTaskStore_Fail498=== PAUSE TestGCTaskStore_Fail499=== RUN TestGracefulShutdownDrainsInflight500=== PAUSE TestGracefulShutdownDrainsInflight501=== RUN TestService_healthCheckHandler502=== PAUSE TestService_healthCheckHandler503=== RUN TestService_readinessHandler504=== PAUSE TestService_readinessHandler505=== RUN TestGenerateLandingPage506=== PAUSE TestGenerateLandingPage507=== RUN TestCacheConfigHandlerMaxNarSize508=== PAUSE TestCacheConfigHandlerMaxNarSize509=== RUN TestCreatePendingClosureRejectsOversizedNAR510=== PAUSE TestCreatePendingClosureRejectsOversizedNAR511=== RUN TestNARDeduplicationMetadataUploadBug512=== PAUSE TestNARDeduplicationMetadataUploadBug513=== RUN TestMetricsInventory514=== PAUSE TestMetricsInventory515=== RUN TestService_NativeMTLS516=== PAUSE TestService_NativeMTLS517=== RUN TestServerTLSConfig518=== PAUSE TestServerTLSConfig519=== RUN TestMultipartCleanup520=== PAUSE TestMultipartCleanup521=== RUN TestObjectStatsTrigger522=== PAUSE TestObjectStatsTrigger523=== RUN TestOrphanedObjectsGC524=== PAUSE TestOrphanedObjectsGC525=== RUN TestOrphanedObjectsGCStressTest526=== PAUSE TestOrphanedObjectsGCStressTest527=== RUN TestResurrectedObjectNotDeleted528=== PAUSE TestResurrectedObjectNotDeleted529=== RUN TestParseSingleRange530=== PAUSE TestParseSingleRange531=== RUN TestIsValidCachePath532=== PAUSE TestIsValidCachePath533=== RUN TestReadProxyNarinfo534=== PAUSE TestReadProxyNarinfo535=== RUN TestReadProxyNarinfoAlreadyDecompressed536=== PAUSE TestReadProxyNarinfoAlreadyDecompressed537=== RUN TestReadProxyNarStreaming538=== PAUSE TestReadProxyNarStreaming539=== RUN TestReadProxy404540=== PAUSE TestReadProxy404541=== RUN TestReadProxyInvalidPath542=== PAUSE TestReadProxyInvalidPath543=== RUN TestReadProxyHead544=== PAUSE TestReadProxyHead545=== RUN TestReadProxyConditionalGet546=== PAUSE TestReadProxyConditionalGet547=== RUN TestReadProxyRootRedirectsToIndexHTML548=== PAUSE TestReadProxyRootRedirectsToIndexHTML549=== RUN TestReadProxyDisabled550=== PAUSE TestReadProxyDisabled551=== RUN TestReadRedirectNar552=== PAUSE TestReadRedirectNar553=== RUN TestReadRedirectKeepsNarinfoProxied554=== PAUSE TestReadRedirectKeepsNarinfoProxied555=== RUN TestReadProxyRangeRequest556=== PAUSE TestReadProxyRangeRequest557=== RUN TestReadRedirectUsesPublicS3URL558=== PAUSE TestReadRedirectUsesPublicS3URL559=== RUN TestRedundantMultipartUpload560=== PAUSE TestRedundantMultipartUpload561=== RUN TestCompleteMultipartUpload_ErrorButObjectExists562=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists563=== RUN TestCompletedNarNotReofferedAcrossClosures564=== PAUSE TestCompletedNarNotReofferedAcrossClosures565=== RUN TestPresignedUploadRegisteredBeforeCommit566=== PAUSE TestPresignedUploadRegisteredBeforeCommit567=== RUN TestService_Rustfstest568=== PAUSE TestService_Rustfstest569=== RUN TestParseSize570=== PAUSE TestParseSize571=== RUN TestSkippedUploadsHandler572=== PAUSE TestSkippedUploadsHandler573=== RUN TestSystemdListenerNotActivated574--- PASS: TestSystemdListenerNotActivated (0.00s)575=== RUN TestWatchdogBeatsWhenHealthy576--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)577=== RUN TestWatchdogSkipsWhenUnhealthy5782026/09/16 23:48:59 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5792026/09/16 23:48:59 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5802026/09/16 23:48:59 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5812026/09/16 23:48:59 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5822026/09/16 23:48:59 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5832026/09/16 23:48:59 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5842026/09/16 23:48:59 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5852026/09/16 23:48:59 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5862026/09/16 23:48:59 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5872026/09/16 23:48:59 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"588--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)589=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle590=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle591=== RUN TestProxyWriteTimeout592=== PAUSE TestProxyWriteTimeout593=== RUN TestIsValidUploadKey594=== PAUSE TestIsValidUploadKey595=== RUN TestUploadHandlersRejectInvalidKeys596=== PAUSE TestUploadHandlersRejectInvalidKeys597=== RUN TestUploadHandlersRejectOversizedBody598=== PAUSE TestUploadHandlersRejectOversizedBody599=== RUN TestService_cleanupPendingClosuresHandler600=== PAUSE TestService_cleanupPendingClosuresHandler601=== RUN TestService_createPendingClosureHandler602=== PAUSE TestService_createPendingClosureHandler603=== RUN TestService_verifyS3Integrity604=== PAUSE TestService_verifyS3Integrity605=== RUN TestCompleteMultipartUnregistered606=== PAUSE TestCompleteMultipartUnregistered607=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT608=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT609=== CONT TestService_AuthMiddleware610=== CONT TestCompleteMultipartUnregistered611=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT612=== CONT TestCacheConfigHandlerMaxNarSize613=== CONT TestService_verifyS3Integrity614=== CONT TestService_createPendingClosureHandler615--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)616=== CONT TestReadProxyRootRedirectsToIndexHTML617=== CONT TestService_cleanupPendingClosuresHandler618=== CONT TestUploadHandlersRejectOversizedBody619=== CONT TestUploadHandlersRejectInvalidKeys620=== CONT TestIsValidUploadKey621=== CONT TestProxyWriteTimeout622=== RUN TestProxyWriteTimeout/narinfo623=== PAUSE TestProxyWriteTimeout/narinfo624=== RUN TestProxyWriteTimeout/1_GiB_nar625=== PAUSE TestProxyWriteTimeout/1_GiB_nar626=== RUN TestProxyWriteTimeout/10_GiB_nar627=== PAUSE TestProxyWriteTimeout/10_GiB_nar628=== RUN TestProxyWriteTimeout/unknown_size629=== PAUSE TestProxyWriteTimeout/unknown_size630=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle631=== CONT TestReadProxyConditionalGet632=== CONT TestSkippedUploadsHandler633=== CONT TestParseSize634=== CONT TestService_Rustfstest635=== CONT TestPresignedUploadRegisteredBeforeCommit636=== CONT TestCompletedNarNotReofferedAcrossClosures637=== CONT TestCompleteMultipartUpload_ErrorButObjectExists638=== CONT TestRedundantMultipartUpload639=== CONT TestReadRedirectUsesPublicS3URL640=== CONT TestReadProxyRangeRequest641=== CONT TestReadRedirectKeepsNarinfoProxied642=== CONT TestReadRedirectNar643=== CONT TestReadProxyDisabled644=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info645=== RUN TestIsValidUploadKey/narinfo646=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info647=== PAUSE TestIsValidUploadKey/narinfo648=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal649--- PASS: TestParseSize (0.00s)650=== RUN TestIsValidUploadKey/nar_zst651=== PAUSE TestIsValidUploadKey/nar_zst652=== RUN TestIsValidUploadKey/nar_xz6532026/09/16 23:48:59 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000654=== CONT TestReadProxyHead655=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal656=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key657=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key658=== PAUSE TestIsValidUploadKey/nar_xz659=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key660=== RUN TestIsValidUploadKey/nar_plain661=== PAUSE TestIsValidUploadKey/nar_plain662=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key663=== RUN TestIsValidUploadKey/listing664=== CONT TestReadProxyInvalidPath665=== PAUSE TestIsValidUploadKey/listing666=== RUN TestIsValidUploadKey/build_log667=== PAUSE TestIsValidUploadKey/build_log668=== RUN TestIsValidUploadKey/build_log_home-manager_file669=== PAUSE TestIsValidUploadKey/build_log_home-manager_file670=== RUN TestIsValidUploadKey/build_log_plus_in_name671=== PAUSE TestIsValidUploadKey/build_log_plus_in_name672=== RUN TestIsValidUploadKey/build_log_question_mark673=== PAUSE TestIsValidUploadKey/build_log_question_mark674=== RUN TestIsValidUploadKey/build_log_equals675=== PAUSE TestIsValidUploadKey/build_log_equals676=== RUN TestIsValidUploadKey/realisation677=== PAUSE TestIsValidUploadKey/realisation678=== RUN TestIsValidUploadKey/realisation_plus_in_output679=== PAUSE TestIsValidUploadKey/realisation_plus_in_output680=== RUN TestIsValidUploadKey/nix-cache-info681=== PAUSE TestIsValidUploadKey/nix-cache-info682=== RUN TestIsValidUploadKey/index.html683=== PAUSE TestIsValidUploadKey/index.html684=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure685=== RUN TestIsValidUploadKey/narinfo_key,_nar_type686=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure687=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type688=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart689=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart690=== RUN TestIsValidUploadKey/nar_key,_narinfo_type691=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type692=== RUN TestIsValidUploadKey/listing_key,_narinfo_type693=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type694=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts695=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts696=== RUN TestIsValidUploadKey/traversal697=== PAUSE TestIsValidUploadKey/traversal698=== RUN TestIsValidUploadKey/traversal_nar699=== PAUSE TestIsValidUploadKey/traversal_nar700=== RUN TestIsValidUploadKey/absolute701=== PAUSE TestIsValidUploadKey/absolute702=== RUN TestIsValidUploadKey/empty_key703=== CONT TestReadProxy404704=== PAUSE TestIsValidUploadKey/empty_key705=== RUN TestIsValidUploadKey/unknown_type706=== PAUSE TestIsValidUploadKey/unknown_type707=== CONT TestReadProxyNarStreaming708--- PASS: TestSkippedUploadsHandler (0.15s)709=== CONT TestReadProxyNarinfoAlreadyDecompressed7102026-09-16 23:48:59.442 UTC [634] ERROR: relation "goose_db_version" does not exist at character 367112026-09-16 23:48:59.442 UTC [634] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7122026-09-16 23:48:59.489 UTC [641] ERROR: relation "goose_db_version" does not exist at character 367132026-09-16 23:48:59.489 UTC [641] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7142026-09-16 23:48:59.512 UTC [642] ERROR: relation "goose_db_version" does not exist at character 367152026-09-16 23:48:59.512 UTC [642] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7162026-09-16 23:48:59.512 UTC [643] ERROR: relation "goose_db_version" does not exist at character 367172026-09-16 23:48:59.512 UTC [643] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7182026-09-16 23:48:59.514 UTC [644] ERROR: relation "goose_db_version" does not exist at character 367192026-09-16 23:48:59.514 UTC [644] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7202026/09/16 23:48:59 OK 20241026095416_initial_model.sql (76.85ms)7212026/09/16 23:48:59 OK 20251210153512_drop_unused_gin_index.sql (3.21ms)7222026-09-16 23:48:59.551 UTC [645] ERROR: relation "goose_db_version" does not exist at character 367232026-09-16 23:48:59.551 UTC [645] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7242026/09/16 23:48:59 OK 20241026095416_initial_model.sql (15.89ms)7252026-09-16 23:48:59.560 UTC [646] ERROR: relation "goose_db_version" does not exist at character 367262026-09-16 23:48:59.560 UTC [646] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7272026/09/16 23:48:59 OK 20241026095416_initial_model.sql (46.87ms)7282026/09/16 23:48:59 OK 20241026095416_initial_model.sql (24.32ms)7292026/09/16 23:48:59 OK 20251218171726_add_pins.sql (19.03ms)7302026/09/16 23:48:59 OK 20241026095416_initial_model.sql (23.93ms)7312026/09/16 23:48:59 OK 20251210153512_drop_unused_gin_index.sql (14.53ms)7322026/09/16 23:48:59 OK 20251210153512_drop_unused_gin_index.sql (5.96ms)7332026/09/16 23:48:59 OK 20251210153512_drop_unused_gin_index.sql (2.97ms)7342026/09/16 23:48:59 OK 20251210153512_drop_unused_gin_index.sql (3.2ms)7352026/09/16 23:48:59 OK 20251218171726_add_pins.sql (4.79ms)7362026/09/16 23:48:59 OK 20251218171726_add_pins.sql (4.8ms)7372026/09/16 23:48:59 OK 20251218171726_add_pins.sql (5.24ms)7382026-09-16 23:48:59.576 UTC [647] ERROR: relation "goose_db_version" does not exist at character 367392026-09-16 23:48:59.576 UTC [647] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7402026/09/16 23:48:59 OK 20251218171726_add_pins.sql (7.29ms)7412026/09/16 23:48:59 OK 20260628120000_add_object_size_and_stats.sql (7.33ms)7422026/09/16 23:48:59 OK 20260628120000_add_object_size_and_stats.sql (12.36ms)7432026/09/16 23:48:59 OK 20260628120000_add_object_size_and_stats.sql (6.98ms)7442026/09/16 23:48:59 OK 20241026095416_initial_model.sql (14.18ms)7452026/09/16 23:48:59 OK 20260628120000_add_object_size_and_stats.sql (7.39ms)7462026/09/16 23:48:59 OK 20251210153512_drop_unused_gin_index.sql (2.86ms)7472026/09/16 23:48:59 OK 20260905000000_add_claims.sql (6.2ms)7482026/09/16 23:48:59 goose: successfully migrated database to version: 202609050000007492026-09-16 23:48:59.587 UTC [648] ERROR: relation "goose_db_version" does not exist at character 367502026-09-16 23:48:59.587 UTC [648] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7512026/09/16 23:48:59 OK 20260905000000_add_claims.sql (6.52ms)7522026/09/16 23:48:59 goose: successfully migrated database to version: 202609050000007532026/09/16 23:48:59 OK 20260628120000_add_object_size_and_stats.sql (9.94ms)7542026/09/16 23:48:59 OK 1_commit_pending_closure.sql (3.96ms)7552026/09/16 23:48:59 OK 1_commit_pending_closure.sql (3.78ms)7562026/09/16 23:48:59 OK 20260905000000_add_claims.sql (11.89ms)7572026/09/16 23:48:59 goose: successfully migrated database to version: 202609050000007582026/09/16 23:48:59 OK 20260905000000_add_claims.sql (8.41ms)7592026/09/16 23:48:59 goose: successfully migrated database to version: 202609050000007602026/09/16 23:48:59 OK 2_object_stats_trigger.sql (2.98ms)7612026/09/16 23:48:59 goose: up to current file version: 27622026/09/16 23:48:59 OK 2_object_stats_trigger.sql (3.02ms)7632026/09/16 23:48:59 goose: up to current file version: 27642026/09/16 23:48:59 OK 20251218171726_add_pins.sql (19.41ms)7652026/09/16 23:48:59 OK 1_commit_pending_closure.sql (12.19ms)7662026/09/16 23:48:59 OK 1_commit_pending_closure.sql (16.48ms)7672026/09/16 23:48:59 OK 20241026095416_initial_model.sql (33.89ms)7682026/09/16 23:48:59 OK 20260905000000_add_claims.sql (20.38ms)7692026/09/16 23:48:59 goose: successfully migrated database to version: 202609050000007702026/09/16 23:48:59 OK 20251210153512_drop_unused_gin_index.sql (2.64ms)7712026/09/16 23:48:59 OK 2_object_stats_trigger.sql (8.34ms)7722026/09/16 23:48:59 goose: up to current file version: 27732026/09/16 23:48:59 OK 2_object_stats_trigger.sql (4.33ms)7742026/09/16 23:48:59 goose: up to current file version: 27752026/09/16 23:48:59 OK 1_commit_pending_closure.sql (5.73ms)7762026/09/16 23:48:59 OK 20260628120000_add_object_size_and_stats.sql (11.74ms)777--- PASS: TestReadProxyRootRedirectsToIndexHTML (0.33s)778=== CONT TestReadProxyNarinfo7792026/09/16 23:48:59 OK 20251218171726_add_pins.sql (6.46ms)7802026/09/16 23:48:59 OK 2_object_stats_trigger.sql (4.56ms)7812026/09/16 23:48:59 goose: up to current file version: 27822026/09/16 23:48:59 OK 20241026095416_initial_model.sql (34.5ms)7832026/09/16 23:48:59 OK 20260905000000_add_claims.sql (6.27ms)7842026/09/16 23:48:59 goose: successfully migrated database to version: 202609050000007852026/09/16 23:48:59 OK 20260628120000_add_object_size_and_stats.sql (7.82ms)7862026/09/16 23:48:59 OK 1_commit_pending_closure.sql (4.8ms)7872026/09/16 23:48:59 OK 20251210153512_drop_unused_gin_index.sql (6.5ms)7882026/09/16 23:48:59 OK 2_object_stats_trigger.sql (2.78ms)7892026/09/16 23:48:59 goose: up to current file version: 27902026/09/16 23:48:59 OK 20260905000000_add_claims.sql (4.69ms)7912026/09/16 23:48:59 goose: successfully migrated database to version: 202609050000007922026/09/16 23:48:59 INFO Received complete multipart upload request method=POST path=/api/multipart/complete7932026/09/16 23:48:59 OK 20251218171726_add_pins.sql (4.22ms)7942026/09/16 23:48:59 OK 20241026095416_initial_model.sql (27.43ms)7952026-09-16 23:48:59.633 UTC [652] ERROR: relation "goose_db_version" does not exist at character 367962026-09-16 23:48:59.633 UTC [652] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7972026-09-16 23:48:59.634 UTC [653] ERROR: relation "goose_db_version" does not exist at character 367982026-09-16 23:48:59.634 UTC [653] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7992026-09-16 23:48:59.634 UTC [655] ERROR: relation "goose_db_version" does not exist at character 368002026-09-16 23:48:59.634 UTC [655] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8012026/09/16 23:48:59 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst802--- PASS: TestCompleteMultipartUnregistered (0.35s)803=== CONT TestIsValidCachePath8042026/09/16 23:48:59 OK 1_commit_pending_closure.sql (3.8ms)805=== RUN TestIsValidCachePath/narinfo806=== PAUSE TestIsValidCachePath/narinfo807=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars808=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars809=== RUN TestIsValidCachePath/nar_zst810=== PAUSE TestIsValidCachePath/nar_zst811=== RUN TestIsValidCachePath/nar_xz812=== PAUSE TestIsValidCachePath/nar_xz813=== RUN TestIsValidCachePath/nar_bz2814=== PAUSE TestIsValidCachePath/nar_bz2815=== RUN TestIsValidCachePath/nar_uncompressed816=== PAUSE TestIsValidCachePath/nar_uncompressed817=== RUN TestIsValidCachePath/ls818=== PAUSE TestIsValidCachePath/ls819=== RUN TestIsValidCachePath/log820=== PAUSE TestIsValidCachePath/log821=== RUN TestIsValidCachePath/realisation822=== PAUSE TestIsValidCachePath/realisation823=== RUN TestIsValidCachePath/nix-cache-info824=== PAUSE TestIsValidCachePath/nix-cache-info825=== RUN TestIsValidCachePath/index.html826=== PAUSE TestIsValidCachePath/index.html827=== RUN TestIsValidCachePath/traversal_parent828=== PAUSE TestIsValidCachePath/traversal_parent829=== RUN TestIsValidCachePath/traversal_in_middle830=== PAUSE TestIsValidCachePath/traversal_in_middle831=== RUN TestIsValidCachePath/invalid_char_e832=== PAUSE TestIsValidCachePath/invalid_char_e833=== RUN TestIsValidCachePath/invalid_char_u834=== PAUSE TestIsValidCachePath/invalid_char_u835=== RUN TestIsValidCachePath/random_path836=== PAUSE TestIsValidCachePath/random_path837=== RUN TestIsValidCachePath/empty838=== PAUSE TestIsValidCachePath/empty8392026/09/16 23:48:59 OK 20251210153512_drop_unused_gin_index.sql (3.52ms)840=== RUN TestIsValidCachePath/leading_slash841=== PAUSE TestIsValidCachePath/leading_slash842=== RUN TestIsValidCachePath/wrong_extension843=== PAUSE TestIsValidCachePath/wrong_extension844=== RUN TestIsValidCachePath/short_hash845=== PAUSE TestIsValidCachePath/short_hash846=== CONT TestParseSingleRange847=== RUN TestParseSingleRange/none848=== PAUSE TestParseSingleRange/none849=== RUN TestParseSingleRange/unknown_unit850=== PAUSE TestParseSingleRange/unknown_unit851=== RUN TestParseSingleRange/multi-range_ignored852=== PAUSE TestParseSingleRange/multi-range_ignored853=== RUN TestParseSingleRange/malformed_no_dash854=== PAUSE TestParseSingleRange/malformed_no_dash8552026/09/16 23:48:59 OK 2_object_stats_trigger.sql (2.43ms)856=== RUN TestParseSingleRange/malformed_both_empty8572026/09/16 23:48:59 goose: up to current file version: 2858=== PAUSE TestParseSingleRange/malformed_both_empty859=== RUN TestParseSingleRange/malformed_end_before_start860=== PAUSE TestParseSingleRange/malformed_end_before_start861=== RUN TestParseSingleRange/closed862=== PAUSE TestParseSingleRange/closed863=== RUN TestParseSingleRange/open-ended864=== PAUSE TestParseSingleRange/open-ended865=== RUN TestParseSingleRange/end_clamped_to_size866=== PAUSE TestParseSingleRange/end_clamped_to_size867=== RUN TestParseSingleRange/suffix868=== PAUSE TestParseSingleRange/suffix869=== RUN TestParseSingleRange/suffix_exceeds_size870=== PAUSE TestParseSingleRange/suffix_exceeds_size8712026-09-16 23:48:59.639 UTC [656] ERROR: relation "goose_db_version" does not exist at character 368722026-09-16 23:48:59.639 UTC [656] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC873=== RUN TestParseSingleRange/single_byte874=== PAUSE TestParseSingleRange/single_byte875=== RUN TestParseSingleRange/start_past_EOF876=== PAUSE TestParseSingleRange/start_past_EOF877=== RUN TestParseSingleRange/start_far_past_EOF878=== PAUSE TestParseSingleRange/start_far_past_EOF879=== CONT TestResurrectedObjectNotDeleted8802026/09/16 23:48:59 OK 20260628120000_add_object_size_and_stats.sql (6.61ms)8812026-09-16 23:48:59.646 UTC [658] ERROR: relation "goose_db_version" does not exist at character 368822026-09-16 23:48:59.646 UTC [658] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8832026/09/16 23:48:59 INFO Received cleanup request method=DELETE path=/api/pending_closures8842026/09/16 23:48:59 OK 20260905000000_add_claims.sql (17.07ms)8852026/09/16 23:48:59 goose: successfully migrated database to version: 202609050000008862026/09/16 23:48:59 OK 20251218171726_add_pins.sql (19.7ms)8872026/09/16 23:48:59 INFO Aborted multipart uploads count=08882026/09/16 23:48:59 OK 1_commit_pending_closure.sql (3.37ms)8892026/09/16 23:48:59 INFO Received uploads request method=POST path=/api/pending_closures8902026/09/16 23:48:59 OK 2_object_stats_trigger.sql (2.44ms)8912026/09/16 23:48:59 goose: up to current file version: 28922026/09/16 23:48:59 OK 20260628120000_add_object_size_and_stats.sql (8.3ms)8932026-09-16 23:48:59.666 UTC [660] ERROR: relation "goose_db_version" does not exist at character 368942026-09-16 23:48:59.666 UTC [660] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8952026-09-16 23:48:59.668 UTC [661] ERROR: relation "goose_db_version" does not exist at character 368962026-09-16 23:48:59.668 UTC [661] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8972026-09-16 23:48:59.668 UTC [662] ERROR: relation "goose_db_version" does not exist at character 368982026-09-16 23:48:59.668 UTC [662] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8992026/09/16 23:48:59 OK 20241026095416_initial_model.sql (14.29ms)9002026-09-16 23:48:59.669 UTC [663] ERROR: relation "goose_db_version" does not exist at character 369012026-09-16 23:48:59.669 UTC [663] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9022026-09-16 23:48:59.669 UTC [664] ERROR: relation "goose_db_version" does not exist at character 369032026-09-16 23:48:59.669 UTC [664] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9042026/09/16 23:48:59 OK 20241026095416_initial_model.sql (12.23ms)9052026/09/16 23:48:59 OK 20241026095416_initial_model.sql (12.48ms)9062026/09/16 23:48:59 OK 20241026095416_initial_model.sql (12.77ms)9072026/09/16 23:48:59 OK 20241026095416_initial_model.sql (12.84ms)9082026-09-16 23:48:59.672 UTC [666] ERROR: relation "goose_db_version" does not exist at character 369092026-09-16 23:48:59.672 UTC [666] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9102026/09/16 23:48:59 OK 20260905000000_add_claims.sql (6.15ms)9112026/09/16 23:48:59 goose: successfully migrated database to version: 202609050000009122026-09-16 23:48:59.672 UTC [665] ERROR: relation "goose_db_version" does not exist at character 369132026-09-16 23:48:59.672 UTC [665] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9142026/09/16 23:48:59 OK 20251210153512_drop_unused_gin_index.sql (2.21ms)9152026/09/16 23:48:59 OK 20251210153512_drop_unused_gin_index.sql (2.92ms)9162026/09/16 23:48:59 OK 20251210153512_drop_unused_gin_index.sql (2.33ms)9172026/09/16 23:48:59 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"918--- PASS: TestService_AuthMiddleware (0.39s)919=== CONT TestClientErrorHandling920=== RUN TestClientErrorHandling/InvalidStorePath921=== PAUSE TestClientErrorHandling/InvalidStorePath922=== RUN TestClientErrorHandling/InvalidAuthToken923=== PAUSE TestClientErrorHandling/InvalidAuthToken924=== RUN TestClientErrorHandling/ServerNotAvailable925=== PAUSE TestClientErrorHandling/ServerNotAvailable926=== CONT TestOrphanedObjectsGCStressTest9272026/09/16 23:48:59 OK 20251210153512_drop_unused_gin_index.sql (3.19ms)9282026/09/16 23:48:59 OK 20251210153512_drop_unused_gin_index.sql (3.11ms)9292026-09-16 23:48:59.676 UTC [667] ERROR: relation "goose_db_version" does not exist at character 369302026-09-16 23:48:59.676 UTC [667] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9312026/09/16 23:48:59 INFO Received cleanup request method=DELETE path=/api/pending_closures9322026/09/16 23:48:59 OK 20251218171726_add_pins.sql (3.9ms)9332026/09/16 23:48:59 OK 1_commit_pending_closure.sql (4.28ms)9342026/09/16 23:48:59 OK 20251218171726_add_pins.sql (4.06ms)9352026/09/16 23:48:59 OK 20251218171726_add_pins.sql (4.11ms)9362026-09-16 23:48:59.677 UTC [668] ERROR: relation "goose_db_version" does not exist at character 369372026-09-16 23:48:59.677 UTC [668] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9382026/09/16 23:48:59 INFO Aborted multipart uploads count=19392026/09/16 23:48:59 OK 2_object_stats_trigger.sql (2.5ms)9402026/09/16 23:48:59 goose: up to current file version: 29412026/09/16 23:48:59 OK 20251218171726_add_pins.sql (4.85ms)9422026/09/16 23:48:59 OK 20251218171726_add_pins.sql (4.77ms)9432026/09/16 23:48:59 OK 20260628120000_add_object_size_and_stats.sql (4.38ms)9442026/09/16 23:48:59 OK 20260628120000_add_object_size_and_stats.sql (5.05ms)9452026/09/16 23:48:59 OK 20260628120000_add_object_size_and_stats.sql (5.14ms)9462026/09/16 23:48:59 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete9472026-09-16 23:48:59.684 UTC [644] ERROR: Closure does not exist: id=19482026-09-16 23:48:59.684 UTC [644] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 16 at RAISE9492026-09-16 23:48:59.684 UTC [644] STATEMENT: -- name: CommitPendingClosure :exec950 SELECT commit_pending_closure($1::bigint)951 952--- PASS: TestService_cleanupPendingClosuresHandler (0.40s)953=== CONT TestGenerateLandingPage9542026/09/16 23:48:59 OK 20260628120000_add_object_size_and_stats.sql (5.1ms)9552026/09/16 23:48:59 OK 20260905000000_add_claims.sql (4.65ms)9562026/09/16 23:48:59 goose: successfully migrated database to version: 202609050000009572026/09/16 23:48:59 OK 20260905000000_add_claims.sql (4ms)9582026/09/16 23:48:59 goose: successfully migrated database to version: 202609050000009592026/09/16 23:48:59 OK 20241026095416_initial_model.sql (12.15ms)9602026/09/16 23:48:59 OK 20260905000000_add_claims.sql (3.92ms)9612026/09/16 23:48:59 goose: successfully migrated database to version: 202609050000009622026/09/16 23:48:59 OK 20260628120000_add_object_size_and_stats.sql (7.2ms)963--- PASS: TestGenerateLandingPage (0.00s)964=== CONT TestOrphanedObjectsGC9652026/09/16 23:48:59 OK 20251210153512_drop_unused_gin_index.sql (1.43ms)9662026/09/16 23:48:59 OK 20241026095416_initial_model.sql (12.94ms)9672026/09/16 23:48:59 OK 1_commit_pending_closure.sql (2.84ms)9682026/09/16 23:48:59 OK 1_commit_pending_closure.sql (3.43ms)9692026/09/16 23:48:59 OK 1_commit_pending_closure.sql (3.28ms)9702026/09/16 23:48:59 OK 20260905000000_add_claims.sql (4.45ms)9712026/09/16 23:48:59 goose: successfully migrated database to version: 202609050000009722026/09/16 23:48:59 OK 20251210153512_drop_unused_gin_index.sql (1.87ms)9732026/09/16 23:48:59 OK 2_object_stats_trigger.sql (1.49ms)9742026/09/16 23:48:59 goose: up to current file version: 29752026/09/16 23:48:59 OK 2_object_stats_trigger.sql (2.39ms)9762026/09/16 23:48:59 OK 20241026095416_initial_model.sql (13.45ms)9772026/09/16 23:48:59 OK 2_object_stats_trigger.sql (2.33ms)9782026/09/16 23:48:59 goose: up to current file version: 29792026-09-16 23:48:59.692 UTC [671] ERROR: relation "goose_db_version" does not exist at character 369802026-09-16 23:48:59.692 UTC [671] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9812026/09/16 23:48:59 goose: up to current file version: 29822026/09/16 23:48:59 OK 1_commit_pending_closure.sql (3.31ms)9832026/09/16 23:48:59 OK 20241026095416_initial_model.sql (13.07ms)9842026/09/16 23:48:59 OK 20251218171726_add_pins.sql (5.4ms)9852026/09/16 23:48:59 OK 20260905000000_add_claims.sql (6.24ms)9862026/09/16 23:48:59 goose: successfully migrated database to version: 202609050000009872026/09/16 23:48:59 OK 20241026095416_initial_model.sql (14.63ms)9882026/09/16 23:48:59 OK 20251218171726_add_pins.sql (3.8ms)9892026/09/16 23:48:59 OK 20241026095416_initial_model.sql (14.03ms)9902026/09/16 23:48:59 OK 20241026095416_initial_model.sql (13.36ms)9912026/09/16 23:48:59 OK 20251210153512_drop_unused_gin_index.sql (2.2ms)9922026/09/16 23:48:59 OK 2_object_stats_trigger.sql (2.35ms)9932026/09/16 23:48:59 goose: up to current file version: 29942026/09/16 23:48:59 OK 20251210153512_drop_unused_gin_index.sql (1.84ms)9952026/09/16 23:48:59 OK 20251210153512_drop_unused_gin_index.sql (3.05ms)9962026/09/16 23:48:59 OK 20251210153512_drop_unused_gin_index.sql (2.59ms)9972026/09/16 23:48:59 OK 1_commit_pending_closure.sql (3.71ms)9982026/09/16 23:48:59 OK 20251210153512_drop_unused_gin_index.sql (2.91ms)9992026/09/16 23:48:59 INFO Received uploads request method=POST path=/api/pending_closures10002026/09/16 23:48:59 OK 20251218171726_add_pins.sql (3.94ms)10012026/09/16 23:48:59 OK 20260628120000_add_object_size_and_stats.sql (5.13ms)10022026/09/16 23:48:59 OK 20241026095416_initial_model.sql (13.78ms)10032026/09/16 23:48:59 OK 2_object_stats_trigger.sql (2.24ms)10042026/09/16 23:48:59 goose: up to current file version: 210052026/09/16 23:48:59 OK 20241026095416_initial_model.sql (14.19ms)10062026/09/16 23:48:59 OK 20260628120000_add_object_size_and_stats.sql (5.43ms)10072026/09/16 23:48:59 OK 20251218171726_add_pins.sql (4.25ms)10082026/09/16 23:48:59 OK 20251218171726_add_pins.sql (4.44ms)10092026/09/16 23:48:59 OK 20251210153512_drop_unused_gin_index.sql (2.04ms)10102026/09/16 23:48:59 OK 20251218171726_add_pins.sql (4.56ms)10112026/09/16 23:48:59 OK 20251218171726_add_pins.sql (4.38ms)10122026/09/16 23:48:59 OK 20251210153512_drop_unused_gin_index.sql (2.18ms)10132026/09/16 23:48:59 OK 20260905000000_add_claims.sql (4.22ms)10142026/09/16 23:48:59 goose: successfully migrated database to version: 2026090500000010152026/09/16 23:48:59 OK 20260905000000_add_claims.sql (4.12ms)10162026/09/16 23:48:59 goose: successfully migrated database to version: 2026090500000010172026/09/16 23:48:59 OK 20260628120000_add_object_size_and_stats.sql (5.31ms)10182026/09/16 23:48:59 OK 20251218171726_add_pins.sql (3.81ms)10192026/09/16 23:48:59 OK 20260628120000_add_object_size_and_stats.sql (4.04ms)10202026/09/16 23:48:59 OK 20251218171726_add_pins.sql (3.84ms)10212026/09/16 23:48:59 OK 20260628120000_add_object_size_and_stats.sql (4.71ms)10222026/09/16 23:48:59 OK 20260628120000_add_object_size_and_stats.sql (4.91ms)10232026/09/16 23:48:59 OK 1_commit_pending_closure.sql (2.77ms)10242026/09/16 23:48:59 OK 1_commit_pending_closure.sql (2.68ms)10252026/09/16 23:48:59 OK 20260628120000_add_object_size_and_stats.sql (5.05ms)10262026/09/16 23:48:59 OK 2_object_stats_trigger.sql (1.86ms)10272026/09/16 23:48:59 goose: up to current file version: 210282026/09/16 23:48:59 OK 2_object_stats_trigger.sql (2.36ms)10292026/09/16 23:48:59 goose: up to current file version: 210302026/09/16 23:48:59 OK 20260905000000_add_claims.sql (4.3ms)10312026/09/16 23:48:59 goose: successfully migrated database to version: 2026090500000010322026/09/16 23:48:59 OK 20260905000000_add_claims.sql (5.14ms)10332026/09/16 23:48:59 goose: successfully migrated database to version: 2026090500000010342026/09/16 23:48:59 OK 20260905000000_add_claims.sql (4.37ms)10352026/09/16 23:48:59 goose: successfully migrated database to version: 2026090500000010362026/09/16 23:48:59 OK 20260628120000_add_object_size_and_stats.sql (5.53ms)10372026/09/16 23:48:59 OK 20260628120000_add_object_size_and_stats.sql (5.7ms)10382026/09/16 23:48:59 OK 20241026095416_initial_model.sql (12.74ms)10392026/09/16 23:48:59 OK 20260905000000_add_claims.sql (5.69ms)10402026/09/16 23:48:59 goose: successfully migrated database to version: 2026090500000010412026/09/16 23:48:59 OK 1_commit_pending_closure.sql (3.11ms)10422026/09/16 23:48:59 OK 1_commit_pending_closure.sql (3.46ms)10432026/09/16 23:48:59 OK 20260905000000_add_claims.sql (5.97ms)10442026/09/16 23:48:59 goose: successfully migrated database to version: 2026090500000010452026/09/16 23:48:59 OK 1_commit_pending_closure.sql (3.34ms)10462026/09/16 23:48:59 OK 20251210153512_drop_unused_gin_index.sql (2.21ms)10472026/09/16 23:48:59 OK 2_object_stats_trigger.sql (2.03ms)10482026/09/16 23:48:59 goose: up to current file version: 210492026/09/16 23:48:59 OK 2_object_stats_trigger.sql (1.94ms)10502026/09/16 23:48:59 goose: up to current file version: 210512026/09/16 23:48:59 OK 20260905000000_add_claims.sql (4.27ms)10522026/09/16 23:48:59 goose: successfully migrated database to version: 2026090500000010532026/09/16 23:48:59 OK 1_commit_pending_closure.sql (2.98ms)10542026/09/16 23:48:59 OK 2_object_stats_trigger.sql (1.8ms)10552026/09/16 23:48:59 goose: up to current file version: 210562026/09/16 23:48:59 OK 20260905000000_add_claims.sql (4.42ms)10572026/09/16 23:48:59 goose: successfully migrated database to version: 2026090500000010582026/09/16 23:48:59 OK 1_commit_pending_closure.sql (2.92ms)10592026/09/16 23:48:59 OK 2_object_stats_trigger.sql (1.58ms)10602026/09/16 23:48:59 goose: up to current file version: 210612026/09/16 23:48:59 OK 20251218171726_add_pins.sql (3.77ms)10622026/09/16 23:48:59 OK 2_object_stats_trigger.sql (1.67ms)10632026/09/16 23:48:59 goose: up to current file version: 210642026/09/16 23:48:59 OK 1_commit_pending_closure.sql (2.68ms)10652026/09/16 23:48:59 OK 1_commit_pending_closure.sql (2.77ms)10662026/09/16 23:48:59 OK 2_object_stats_trigger.sql (2ms)10672026/09/16 23:48:59 goose: up to current file version: 210682026/09/16 23:48:59 OK 2_object_stats_trigger.sql (2.23ms)10692026/09/16 23:48:59 goose: up to current file version: 210702026/09/16 23:48:59 OK 20260628120000_add_object_size_and_stats.sql (3.95ms)10712026/09/16 23:48:59 OK 20260905000000_add_claims.sql (3.42ms)10722026/09/16 23:48:59 goose: successfully migrated database to version: 202609050000001073--- PASS: TestReadRedirectUsesPublicS3URL (0.44s)1074=== CONT TestObjectStatsTrigger10752026/09/16 23:48:59 OK 1_commit_pending_closure.sql (10.94ms)10762026/09/16 23:48:59 OK 2_object_stats_trigger.sql (3.11ms)10772026/09/16 23:48:59 goose: up to current file version: 210782026/09/16 23:48:59 INFO Received uploads request method=POST path=/api/pending_closures10792026-09-16 23:48:59.754 UTC [676] ERROR: relation "goose_db_version" does not exist at character 3610802026-09-16 23:48:59.754 UTC [676] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10812026-09-16 23:48:59.756 UTC [677] ERROR: relation "goose_db_version" does not exist at character 3610822026-09-16 23:48:59.756 UTC [677] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10832026/09/16 23:48:59 INFO Received uploads request method=POST path=/api/pending_closures10842026/09/16 23:48:59 OK 20241026095416_initial_model.sql (8.83ms)10852026/09/16 23:48:59 OK 20241026095416_initial_model.sql (8.38ms)10862026/09/16 23:48:59 OK 20251210153512_drop_unused_gin_index.sql (1.86ms)10872026/09/16 23:48:59 OK 20251210153512_drop_unused_gin_index.sql (1.17ms)10882026/09/16 23:48:59 OK 20251218171726_add_pins.sql (2.71ms)10892026/09/16 23:48:59 OK 20251218171726_add_pins.sql (2.72ms)10902026/09/16 23:48:59 OK 20260628120000_add_object_size_and_stats.sql (4.24ms)10912026/09/16 23:48:59 OK 20260628120000_add_object_size_and_stats.sql (3.28ms)10922026/09/16 23:48:59 OK 20260905000000_add_claims.sql (2.73ms)10932026/09/16 23:48:59 goose: successfully migrated database to version: 2026090500000010942026-09-16 23:48:59.781 UTC [678] ERROR: relation "goose_db_version" does not exist at character 3610952026-09-16 23:48:59.781 UTC [678] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10962026/09/16 23:48:59 OK 20260905000000_add_claims.sql (3.3ms)10972026/09/16 23:48:59 goose: successfully migrated database to version: 2026090500000010982026/09/16 23:48:59 OK 1_commit_pending_closure.sql (1.51ms)1099--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.50s)1100=== CONT TestMultipartCleanup11012026/09/16 23:48:59 OK 2_object_stats_trigger.sql (1.03ms)11022026/09/16 23:48:59 goose: up to current file version: 211032026/09/16 23:48:59 OK 1_commit_pending_closure.sql (1.8ms)11042026/09/16 23:48:59 OK 2_object_stats_trigger.sql (1.33ms)11052026/09/16 23:48:59 goose: up to current file version: 211062026-09-16 23:48:59.786 UTC [679] ERROR: relation "goose_db_version" does not exist at character 3611072026-09-16 23:48:59.786 UTC [679] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11082026/09/16 23:48:59 OK 20241026095416_initial_model.sql (8.19ms)11092026/09/16 23:48:59 OK 20251210153512_drop_unused_gin_index.sql (2.35ms)11102026/09/16 23:48:59 OK 20241026095416_initial_model.sql (8.19ms)11112026/09/16 23:48:59 OK 20251218171726_add_pins.sql (3.37ms)1112--- PASS: TestReadRedirectKeepsNarinfoProxied (0.51s)1113=== CONT TestServerTLSConfig1114=== RUN TestServerTLSConfig/no_client_CA1115=== PAUSE TestServerTLSConfig/no_client_CA1116=== RUN TestServerTLSConfig/missing_CA_file1117=== PAUSE TestServerTLSConfig/missing_CA_file1118=== RUN TestServerTLSConfig/not_a_PEM_file1119=== PAUSE TestServerTLSConfig/not_a_PEM_file1120=== CONT TestService_NativeMTLS11212026/09/16 23:48:59 OK 20251210153512_drop_unused_gin_index.sql (1.35ms)11222026/09/16 23:48:59 OK 20251218171726_add_pins.sql (3.08ms)11232026/09/16 23:48:59 OK 20260628120000_add_object_size_and_stats.sql (4.83ms)11242026/09/16 23:48:59 OK 20260628120000_add_object_size_and_stats.sql (3.04ms)11252026/09/16 23:48:59 OK 20260905000000_add_claims.sql (2.84ms)11262026/09/16 23:48:59 goose: successfully migrated database to version: 2026090500000011272026/09/16 23:48:59 INFO Received uploads request method=POST path=/api/pending_closures11282026/09/16 23:48:59 OK 20260905000000_add_claims.sql (3.17ms)11292026/09/16 23:48:59 goose: successfully migrated database to version: 2026090500000011302026/09/16 23:48:59 OK 1_commit_pending_closure.sql (3.57ms)11312026/09/16 23:48:59 OK 1_commit_pending_closure.sql (2.24ms)11322026/09/16 23:48:59 OK 2_object_stats_trigger.sql (1.75ms)11332026/09/16 23:48:59 goose: up to current file version: 211342026/09/16 23:48:59 OK 2_object_stats_trigger.sql (1.3ms)11352026/09/16 23:48:59 goose: up to current file version: 211362026/09/16 23:48:59 INFO Received uploads request method=POST path=/api/pending_closures11372026-09-16 23:48:59.824 UTC [684] ERROR: relation "goose_db_version" does not exist at character 3611382026-09-16 23:48:59.824 UTC [684] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1139--- PASS: TestReadProxyConditionalGet (0.56s)1140=== CONT TestMetricsInventory11412026/09/16 23:48:59 OK 20241026095416_initial_model.sql (17.58ms)11422026/09/16 23:48:59 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11432026/09/16 23:48:59 OK 20251210153512_drop_unused_gin_index.sql (3.01ms)11442026/09/16 23:48:59 OK 20251218171726_add_pins.sql (3.64ms)11452026/09/16 23:48:59 INFO Received uploads request method=POST path=/api/pending_closures11462026/09/16 23:48:59 OK 20260628120000_add_object_size_and_stats.sql (3.17ms)11472026/09/16 23:48:59 OK 20260905000000_add_claims.sql (3.31ms)11482026/09/16 23:48:59 goose: successfully migrated database to version: 2026090500000011492026/09/16 23:48:59 OK 1_commit_pending_closure.sql (2.03ms)11502026/09/16 23:48:59 OK 2_object_stats_trigger.sql (1.71ms)11512026/09/16 23:48:59 goose: up to current file version: 211522026-09-16 23:48:59.873 UTC [688] ERROR: relation "goose_db_version" does not exist at character 3611532026-09-16 23:48:59.873 UTC [688] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1154--- PASS: TestReadProxyDisabled (0.59s)1155=== CONT TestNARDeduplicationMetadataUploadBug11562026/09/16 23:48:59 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst11572026/09/16 23:48:59 INFO Received uploads request method=POST path=/api/pending_closures1158--- PASS: TestPresignedUploadRegisteredBeforeCommit (0.60s)1159=== CONT TestCreatePendingClosureRejectsOversizedNAR11602026/09/16 23:48:59 INFO Received uploads request method=POST path=/api/pending_closures1161--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)1162=== CONT TestService_readinessHandler11632026/09/16 23:48:59 OK 20241026095416_initial_model.sql (8.3ms)11642026-09-16 23:48:59.888 UTC [690] ERROR: relation "goose_db_version" does not exist at character 3611652026-09-16 23:48:59.888 UTC [690] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11662026/09/16 23:48:59 OK 20251210153512_drop_unused_gin_index.sql (1.96ms)11672026/09/16 23:48:59 OK 20251218171726_add_pins.sql (2.83ms)11682026/09/16 23:48:59 OK 20260628120000_add_object_size_and_stats.sql (3.42ms)11692026/09/16 23:48:59 INFO Received uploads request method=POST path=/api/pending_closures11702026/09/16 23:48:59 INFO Received uploads request method=POST path=/api/pending_closures11712026/09/16 23:48:59 INFO Received uploads request method=POST path=/api/pending_closures11722026/09/16 23:48:59 OK 20260905000000_add_claims.sql (4.03ms)11732026/09/16 23:48:59 goose: successfully migrated database to version: 2026090500000011742026/09/16 23:48:59 OK 1_commit_pending_closure.sql (2.59ms)11752026/09/16 23:48:59 OK 2_object_stats_trigger.sql (1.94ms)11762026/09/16 23:48:59 goose: up to current file version: 211772026/09/16 23:48:59 OK 20241026095416_initial_model.sql (12.38ms)11782026/09/16 23:48:59 OK 20251210153512_drop_unused_gin_index.sql (1.77ms)11792026/09/16 23:48:59 OK 20251218171726_add_pins.sql (2.92ms)11802026/09/16 23:48:59 OK 20260628120000_add_object_size_and_stats.sql (4.73ms)11812026/09/16 23:48:59 OK 20260905000000_add_claims.sql (3.5ms)11822026/09/16 23:48:59 goose: successfully migrated database to version: 2026090500000011832026/09/16 23:48:59 OK 1_commit_pending_closure.sql (2.22ms)11842026/09/16 23:48:59 OK 2_object_stats_trigger.sql (1.3ms)11852026/09/16 23:48:59 goose: up to current file version: 21186--- PASS: TestReadProxyHead (0.58s)1187=== CONT TestGCTaskStore_StartNew1188--- PASS: TestGCTaskStore_StartNew (0.00s)1189=== CONT TestGCMetrics11902026-09-16 23:48:59.936 UTC [694] ERROR: relation "goose_db_version" does not exist at character 3611912026-09-16 23:48:59.936 UTC [694] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11922026/09/16 23:48:59 OK 20241026095416_initial_model.sql (9.19ms)1193--- PASS: TestReadProxyNarStreaming (0.52s)1194=== CONT TestGCTaskStore_DeduplicateSameParams1195--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)1196=== CONT TestGCBugBareHashReferences11972026/09/16 23:48:59 OK 20251210153512_drop_unused_gin_index.sql (3.13ms)11982026/09/16 23:48:59 OK 20251218171726_add_pins.sql (2.62ms)11992026/09/16 23:48:59 OK 20260628120000_add_object_size_and_stats.sql (4.17ms)12002026-09-16 23:48:59.972 UTC [698] ERROR: relation "goose_db_version" does not exist at character 3612012026-09-16 23:48:59.972 UTC [698] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12022026-09-16 23:48:59.973 UTC [700] ERROR: relation "goose_db_version" does not exist at character 3612032026-09-16 23:48:59.973 UTC [700] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12042026/09/16 23:48:59 OK 20260905000000_add_claims.sql (2.72ms)12052026/09/16 23:48:59 goose: successfully migrated database to version: 2026090500000012062026/09/16 23:48:59 OK 1_commit_pending_closure.sql (2.6ms)12072026/09/16 23:48:59 OK 2_object_stats_trigger.sql (2.07ms)12082026/09/16 23:48:59 goose: up to current file version: 21209--- PASS: TestReadRedirectNar (0.63s)1210=== CONT TestService_healthCheckHandler12112026/09/16 23:48:59 OK 20241026095416_initial_model.sql (8.98ms)12122026/09/16 23:48:59 OK 20241026095416_initial_model.sql (8.99ms)12132026/09/16 23:48:59 OK 20251210153512_drop_unused_gin_index.sql (2.33ms)12142026/09/16 23:48:59 OK 20251210153512_drop_unused_gin_index.sql (2.26ms)12152026/09/16 23:48:59 OK 20251218171726_add_pins.sql (2.92ms)12162026/09/16 23:48:59 OK 20251218171726_add_pins.sql (2.96ms)12172026/09/16 23:48:59 OK 20260628120000_add_object_size_and_stats.sql (3.22ms)12182026/09/16 23:48:59 OK 20260628120000_add_object_size_and_stats.sql (3.66ms)12192026/09/16 23:48:59 OK 20260905000000_add_claims.sql (2.63ms)12202026/09/16 23:48:59 goose: successfully migrated database to version: 2026090500000012212026/09/16 23:49:00 OK 20260905000000_add_claims.sql (3.72ms)12222026/09/16 23:49:00 goose: successfully migrated database to version: 2026090500000012232026/09/16 23:49:00 OK 1_commit_pending_closure.sql (3.36ms)12242026/09/16 23:49:00 OK 2_object_stats_trigger.sql (1.46ms)12252026/09/16 23:49:00 goose: up to current file version: 212262026/09/16 23:49:00 OK 1_commit_pending_closure.sql (3.56ms)12272026/09/16 23:49:00 OK 2_object_stats_trigger.sql (1.85ms)12282026/09/16 23:49:00 goose: up to current file version: 21229--- PASS: TestReadProxyRangeRequest (0.73s)1230=== CONT TestResolveDBConnectionString1231=== RUN TestResolveDBConnectionString/flag_wins1232=== PAUSE TestResolveDBConnectionString/flag_wins1233=== RUN TestResolveDBConnectionString/file_when_flag_empty1234=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1235=== RUN TestResolveDBConnectionString/missing_file_is_an_error1236=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1237=== RUN TestResolveDBConnectionString/PGHOST_allows_empty1238=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1239=== RUN TestResolveDBConnectionString/nothing_configured1240=== PAUSE TestResolveDBConnectionString/nothing_configured1241=== CONT TestGracefulShutdownDrainsInflight12422026/09/16 23:49:00 INFO Starting HTTP server address=127.0.0.1:4582912432026/09/16 23:49:00 INFO Shutdown signal received, draining in-flight requests timeout=10s12442026-09-16 23:49:00.030 UTC [703] ERROR: relation "goose_db_version" does not exist at character 3612452026-09-16 23:49:00.030 UTC [703] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1246--- PASS: TestReadProxyInvalidPath (0.68s)1247=== CONT TestPinProtectsFromGC12482026/09/16 23:49:00 OK 20241026095416_initial_model.sql (8.95ms)12492026/09/16 23:49:00 OK 20251210153512_drop_unused_gin_index.sql (2.22ms)12502026/09/16 23:49:00 OK 20251218171726_add_pins.sql (2.44ms)12512026-09-16 23:49:00.052 UTC [706] ERROR: relation "goose_db_version" does not exist at character 3612522026-09-16 23:49:00.052 UTC [706] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12532026/09/16 23:49:00 OK 20260628120000_add_object_size_and_stats.sql (3.34ms)1254--- PASS: TestReadProxy404 (0.63s)1255=== CONT TestGCTaskStore_Fail1256--- PASS: TestGCTaskStore_Fail (0.00s)1257=== CONT TestClientWithDependencies12582026/09/16 23:49:00 OK 20260905000000_add_claims.sql (11.47ms)12592026/09/16 23:49:00 goose: successfully migrated database to version: 2026090500000012602026/09/16 23:49:00 OK 20241026095416_initial_model.sql (9.94ms)12612026/09/16 23:49:00 OK 1_commit_pending_closure.sql (2.1ms)12622026/09/16 23:49:00 OK 20251210153512_drop_unused_gin_index.sql (1.06ms)12632026/09/16 23:49:00 OK 2_object_stats_trigger.sql (1.14ms)12642026/09/16 23:49:00 goose: up to current file version: 212652026/09/16 23:49:00 OK 20251218171726_add_pins.sql (2.71ms)12662026/09/16 23:49:00 OK 20260628120000_add_object_size_and_stats.sql (2.77ms)12672026/09/16 23:49:00 OK 20260905000000_add_claims.sql (3.05ms)12682026/09/16 23:49:00 goose: successfully migrated database to version: 2026090500000012692026-09-16 23:49:00.078 UTC [709] ERROR: relation "goose_db_version" does not exist at character 3612702026-09-16 23:49:00.078 UTC [709] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12712026/09/16 23:49:00 OK 1_commit_pending_closure.sql (1.98ms)12722026/09/16 23:49:00 OK 2_object_stats_trigger.sql (1.35ms)12732026/09/16 23:49:00 goose: up to current file version: 21274--- PASS: TestGracefulShutdownDrainsInflight (0.07s)1275=== CONT TestGCTaskStore_PhaseUpdates1276--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)1277=== CONT TestClientMultipleUploads12782026/09/16 23:49:00 INFO Received uploads request method=POST path=/api/pending_closures12792026/09/16 23:49:00 OK 20241026095416_initial_model.sql (10.7ms)12802026/09/16 23:49:00 OK 20251210153512_drop_unused_gin_index.sql (2.32ms)12812026/09/16 23:49:00 OK 20251218171726_add_pins.sql (2.62ms)12822026/09/16 23:49:00 OK 20260628120000_add_object_size_and_stats.sql (3.72ms)12832026/09/16 23:49:00 OK 20260905000000_add_claims.sql (3.11ms)12842026/09/16 23:49:00 goose: successfully migrated database to version: 2026090500000012852026/09/16 23:49:00 OK 1_commit_pending_closure.sql (2.4ms)12862026/09/16 23:49:00 OK 2_object_stats_trigger.sql (2.2ms)12872026/09/16 23:49:00 goose: up to current file version: 212882026/09/16 23:49:00 INFO Received uploads request method=POST path=/api/pending_closures12892026/09/16 23:49:00 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12902026-09-16 23:49:00.123 UTC [713] ERROR: relation "goose_db_version" does not exist at character 3612912026-09-16 23:49:00.123 UTC [713] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12922026/09/16 23:49:00 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12932026/09/16 23:49:00 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=N2JlMDI3ZjMtODc4Ny00MjgyLWJjMzUtYzRlM2M4ZWJhN2I1LjkxNTM0YmRiLWIwMjQtNGRjOC1hYzk5LTAyMGEzMDU0YmIyN3gxNzg5NjAyNTQwMTAxMjkxNjcy12942026/09/16 23:49:00 OK 20241026095416_initial_model.sql (11.1ms)12952026/09/16 23:49:00 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=N2JlMDI3ZjMtODc4Ny00MjgyLWJjMzUtYzRlM2M4ZWJhN2I1LjJiOTc4M2RjLWFiOGMtNDNiYi05MzliLTVkNDUwNDZiY2ZkYXgxNzg5NjAyNTM5NzEwNDI3NjI1 parts=1012962026/09/16 23:49:00 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete12972026/09/16 23:49:00 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=N2JlMDI3ZjMtODc4Ny00MjgyLWJjMzUtYzRlM2M4ZWJhN2I1LjkxNTM0YmRiLWIwMjQtNGRjOC1hYzk5LTAyMGEzMDU0YmIyN3gxNzg5NjAyNTQwMTAxMjkxNjcy parts=11298--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (0.85s)1299=== CONT TestGCTaskStore_CompletedAllowsNewTask1300--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)13012026/09/16 23:49:00 OK 20251210153512_drop_unused_gin_index.sql (1.68ms)1302=== CONT TestClientIntegration1303--- PASS: TestService_Rustfstest (0.79s)1304=== CONT TestGCTaskStore_GetReturnsLatest1305--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)1306=== CONT TestClaim_TooManyStreams13072026/09/16 23:49:00 OK 20251218171726_add_pins.sql (2.81ms)13082026/09/16 23:49:00 INFO Completed upload id=113092026/09/16 23:49:00 INFO Received uploads request method=POST path=/api/pending_closures13102026/09/16 23:49:00 OK 20260628120000_add_object_size_and_stats.sql (3.37ms)13112026/09/16 23:49:00 INFO Received uploads request method=POST path=/api/pending_closures13122026/09/16 23:49:00 OK 20260905000000_add_claims.sql (3ms)13132026/09/16 23:49:00 goose: successfully migrated database to version: 2026090500000013142026/09/16 23:49:00 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo13152026/09/16 23:49:00 WARN Found objects in DB but missing from S3, will re-upload count=11316--- PASS: TestService_verifyS3Integrity (0.87s)1317=== CONT TestGCTaskStore_GetEmpty1318--- PASS: TestGCTaskStore_GetEmpty (0.00s)1319=== CONT TestClientCADerivations13202026/09/16 23:49:00 OK 1_commit_pending_closure.sql (2.26ms)13212026/09/16 23:49:00 OK 2_object_stats_trigger.sql (1.03ms)13222026/09/16 23:49:00 goose: up to current file version: 213232026-09-16 23:49:00.161 UTC [734] ERROR: relation "goose_db_version" does not exist at character 3613242026-09-16 23:49:00.161 UTC [734] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13252026/09/16 23:49:00 OK 20241026095416_initial_model.sql (9.28ms)1326--- PASS: TestReadProxyNarinfoAlreadyDecompressed (0.74s)1327=== CONT TestGCTaskStore_ConflictDifferentParams1328--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)1329=== CONT TestPresent13302026-09-16 23:49:00.182 UTC [737] ERROR: relation "goose_db_version" does not exist at character 3613312026-09-16 23:49:00.182 UTC [737] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13322026/09/16 23:49:00 OK 20251210153512_drop_unused_gin_index.sql (10.78ms)13332026/09/16 23:49:00 OK 20251218171726_add_pins.sql (3.12ms)13342026/09/16 23:49:00 OK 20260628120000_add_object_size_and_stats.sql (3.49ms)13352026/09/16 23:49:00 OK 20260905000000_add_claims.sql (3.37ms)13362026/09/16 23:49:00 goose: successfully migrated database to version: 2026090500000013372026/09/16 23:49:00 OK 20241026095416_initial_model.sql (8.74ms)13382026/09/16 23:49:00 OK 1_commit_pending_closure.sql (2.54ms)13392026/09/16 23:49:00 OK 20251210153512_drop_unused_gin_index.sql (3.38ms)13402026/09/16 23:49:00 OK 2_object_stats_trigger.sql (2.45ms)13412026/09/16 23:49:00 goose: up to current file version: 213422026/09/16 23:49:00 OK 20251218171726_add_pins.sql (3.16ms)13432026/09/16 23:49:00 OK 20260628120000_add_object_size_and_stats.sql (4.27ms)1344--- PASS: TestReadProxyNarinfo (0.59s)1345=== CONT TestClaim_StreamsThroughServer13462026/09/16 23:49:00 OK 20260905000000_add_claims.sql (4.28ms)13472026/09/16 23:49:00 goose: successfully migrated database to version: 2026090500000013482026/09/16 23:49:00 OK 1_commit_pending_closure.sql (2.65ms)13492026/09/16 23:49:00 OK 2_object_stats_trigger.sql (1.68ms)13502026/09/16 23:49:00 goose: up to current file version: 213512026-09-16 23:49:00.242 UTC [742] ERROR: relation "goose_db_version" does not exist at character 3613522026-09-16 23:49:00.242 UTC [742] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13532026-09-16 23:49:00.243 UTC [743] ERROR: relation "goose_db_version" does not exist at character 3613542026-09-16 23:49:00.243 UTC [743] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13552026-09-16 23:49:00.248 UTC [744] ERROR: relation "goose_db_version" does not exist at character 3613562026-09-16 23:49:00.248 UTC [744] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13572026/09/16 23:49:00 OK 20241026095416_initial_model.sql (42.7ms)13582026/09/16 23:49:00 OK 20241026095416_initial_model.sql (41.46ms)13592026/09/16 23:49:00 OK 20241026095416_initial_model.sql (39.7ms)13602026/09/16 23:49:00 OK 20251210153512_drop_unused_gin_index.sql (2.36ms)13612026/09/16 23:49:00 OK 20251210153512_drop_unused_gin_index.sql (2.77ms)13622026/09/16 23:49:00 OK 20251210153512_drop_unused_gin_index.sql (2.76ms)13632026/09/16 23:49:00 OK 20251218171726_add_pins.sql (3.21ms)13642026/09/16 23:49:00 OK 20251218171726_add_pins.sql (4.47ms)13652026/09/16 23:49:00 OK 20251218171726_add_pins.sql (3.93ms)13662026/09/16 23:49:00 OK 20260628120000_add_object_size_and_stats.sql (3.4ms)13672026-09-16 23:49:00.304 UTC [745] ERROR: relation "goose_db_version" does not exist at character 3613682026-09-16 23:49:00.304 UTC [745] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13692026/09/16 23:49:00 OK 20260628120000_add_object_size_and_stats.sql (5.26ms)13702026/09/16 23:49:00 OK 20260905000000_add_claims.sql (2.55ms)13712026/09/16 23:49:00 goose: successfully migrated database to version: 2026090500000013722026-09-16 23:49:00.307 UTC [746] ERROR: relation "goose_db_version" does not exist at character 3613732026-09-16 23:49:00.307 UTC [746] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13742026/09/16 23:49:00 OK 20260628120000_add_object_size_and_stats.sql (6.05ms)13752026/09/16 23:49:00 OK 1_commit_pending_closure.sql (2.35ms)13762026/09/16 23:49:00 OK 2_object_stats_trigger.sql (1.02ms)13772026/09/16 23:49:00 goose: up to current file version: 213782026/09/16 23:49:00 OK 20260905000000_add_claims.sql (4.18ms)13792026/09/16 23:49:00 goose: successfully migrated database to version: 2026090500000013802026/09/16 23:49:00 OK 20260905000000_add_claims.sql (3.92ms)13812026/09/16 23:49:00 goose: successfully migrated database to version: 202609050000001382--- PASS: TestResurrectedObjectNotDeleted (0.67s)1383=== CONT TestService_ReadScope_PublicByDefault13842026/09/16 23:49:00 OK 1_commit_pending_closure.sql (2.3ms)13852026/09/16 23:49:00 OK 1_commit_pending_closure.sql (6.34ms)13862026/09/16 23:49:00 OK 2_object_stats_trigger.sql (4.49ms)13872026/09/16 23:49:00 goose: up to current file version: 213882026/09/16 23:49:00 OK 20241026095416_initial_model.sql (8.73ms)13892026/09/16 23:49:00 OK 2_object_stats_trigger.sql (1.2ms)13902026/09/16 23:49:00 goose: up to current file version: 213912026/09/16 23:49:00 OK 20241026095416_initial_model.sql (7.42ms)13922026/09/16 23:49:00 OK 20251210153512_drop_unused_gin_index.sql (946.41µs)13932026/09/16 23:49:00 OK 20251210153512_drop_unused_gin_index.sql (1.15ms)13942026/09/16 23:49:00 OK 20251218171726_add_pins.sql (2.44ms)13952026/09/16 23:49:00 OK 20251218171726_add_pins.sql (2.37ms)13962026/09/16 23:49:00 OK 20260628120000_add_object_size_and_stats.sql (3.44ms)13972026/09/16 23:49:00 OK 20260628120000_add_object_size_and_stats.sql (4.09ms)13982026/09/16 23:49:00 OK 20260905000000_add_claims.sql (2.89ms)13992026/09/16 23:49:00 goose: successfully migrated database to version: 2026090500000014002026/09/16 23:49:00 OK 20260905000000_add_claims.sql (2.34ms)14012026/09/16 23:49:00 goose: successfully migrated database to version: 2026090500000014022026/09/16 23:49:00 OK 1_commit_pending_closure.sql (1.91ms)14032026/09/16 23:49:00 OK 1_commit_pending_closure.sql (1.58ms)14042026/09/16 23:49:00 OK 2_object_stats_trigger.sql (1.03ms)14052026/09/16 23:49:00 goose: up to current file version: 214062026/09/16 23:49:00 OK 2_object_stats_trigger.sql (1.58ms)14072026/09/16 23:49:00 goose: up to current file version: 214082026/09/16 23:49:00 INFO Received complete multipart upload request method=POST path=/api/multipart/complete14092026/09/16 23:49:00 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=N2JlMDI3ZjMtODc4Ny00MjgyLWJjMzUtYzRlM2M4ZWJhN2I1LjVlZTgxMTIwLWYwYzQtNDRkYy04MjYxLTYwNTRmYzk1ZDk5YXgxNzg5NjAyNTM5ODE4MTU5MjU1 parts=121410--- PASS: TestObjectStatsTrigger (0.63s)1411=== CONT TestClaim_InputsTouched1412--- PASS: TestRedundantMultipartUpload (1.07s)1413=== CONT TestClaim_TwoInstances14142026/09/16 23:49:00 INFO Received uploads request method=POST path=/api/pending_closures14152026/09/16 23:49:00 INFO Received complete multipart upload request method=POST path=/api/multipart/complete14162026/09/16 23:49:00 WARN mTLS auth: subject not in bound subjects subject="CN=reader"14172026/09/16 23:49:00 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1418--- PASS: TestService_NativeMTLS (0.59s)1419=== CONT TestClaim_GCMarkedOutputCountsAsAbsent14202026/09/16 23:49:00 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=N2JlMDI3ZjMtODc4Ny00MjgyLWJjMzUtYzRlM2M4ZWJhN2I1LmM3N2ZmMDIxLWFkYzctNDc1My1hOGM4LTNjMzdlZWEwNmEwMngxNzg5NjAyNTM5OTEyMzIxMjMw parts=1014212026/09/16 23:49:00 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete14222026/09/16 23:49:00 INFO Completed upload id=114232026/09/16 23:49:00 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000014242026/09/16 23:49:00 INFO Received uploads request method=POST path=/api/pending_closures14252026/09/16 23:49:00 INFO Starting cleanup of old closures method=DELETE path=/api/closures14262026-09-16 23:49:00.405 UTC [756] ERROR: relation "goose_db_version" does not exist at character 3614272026-09-16 23:49:00.405 UTC [756] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14282026/09/16 23:49:00 INFO Aborted multipart uploads count=014292026/09/16 23:49:00 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=014302026/09/16 23:49:00 OK 20241026095416_initial_model.sql (8.58ms)14312026/09/16 23:49:00 OK 20251210153512_drop_unused_gin_index.sql (2ms)14322026/09/16 23:49:00 INFO Vacuumed table table=pending_closures14332026/09/16 23:49:00 OK 20251218171726_add_pins.sql (2.56ms)14342026/09/16 23:49:00 INFO Vacuumed table table=pending_objects1435--- PASS: TestMetricsInventory (0.59s)1436=== CONT TestClaim_StaleHeartbeatStolen14372026/09/16 23:49:00 OK 20260628120000_add_object_size_and_stats.sql (13.82ms)14382026/09/16 23:49:00 INFO Vacuumed table table=multipart_uploads14392026/09/16 23:49:00 OK 20260905000000_add_claims.sql (3.47ms)14402026/09/16 23:49:00 goose: successfully migrated database to version: 2026090500000014412026/09/16 23:49:00 INFO Vacuumed table table=closures14422026/09/16 23:49:00 OK 1_commit_pending_closure.sql (2.42ms)14432026/09/16 23:49:00 INFO Vacuumed table table=objects14442026/09/16 23:49:00 OK 2_object_stats_trigger.sql (1.47ms)14452026/09/16 23:49:00 goose: up to current file version: 214462026/09/16 23:49:00 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001447--- PASS: TestService_createPendingClosureHandler (1.17s)1448=== CONT TestClaim_BuildWaitComplete14492026/09/16 23:49:00 WARN readiness check failed error="closed pool"1450--- PASS: TestService_readinessHandler (0.57s)1451=== CONT TestClaim_FailWithoutKindReleases14522026-09-16 23:49:00.457 UTC [762] ERROR: relation "goose_db_version" does not exist at character 3614532026-09-16 23:49:00.457 UTC [762] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14542026-09-16 23:49:00.457 UTC [763] ERROR: relation "goose_db_version" does not exist at character 3614552026-09-16 23:49:00.457 UTC [763] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1456=== NAME TestNARDeduplicationMetadataUploadBug1457 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug4061835413/001/store/bsj3kyn585dgqk3ac4nf8k0ysgw56b5r-file1.txt14582026/09/16 23:49:00 OK 20241026095416_initial_model.sql (10.3ms)14592026/09/16 23:49:00 OK 20241026095416_initial_model.sql (10.23ms)14602026/09/16 23:49:00 OK 20251210153512_drop_unused_gin_index.sql (1.75ms)14612026/09/16 23:49:00 OK 20251210153512_drop_unused_gin_index.sql (1.75ms)14622026/09/16 23:49:00 OK 20251218171726_add_pins.sql (3.18ms)14632026/09/16 23:49:00 OK 20251218171726_add_pins.sql (3ms)14642026/09/16 23:49:00 INFO Received cleanup request method=DELETE path=/api/pending_closures14652026/09/16 23:49:00 OK 20260628120000_add_object_size_and_stats.sql (3.57ms)14662026/09/16 23:49:00 OK 20260628120000_add_object_size_and_stats.sql (3.67ms)14672026-09-16 23:49:00.484 UTC [785] ERROR: relation "goose_db_version" does not exist at character 3614682026-09-16 23:49:00.484 UTC [785] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14692026/09/16 23:49:00 INFO Aborted multipart uploads count=114702026/09/16 23:49:00 OK 20260905000000_add_claims.sql (3.34ms)14712026/09/16 23:49:00 goose: successfully migrated database to version: 2026090500000014722026/09/16 23:49:00 OK 20260905000000_add_claims.sql (3.91ms)14732026/09/16 23:49:00 goose: successfully migrated database to version: 2026090500000014742026/09/16 23:49:00 OK 1_commit_pending_closure.sql (2.39ms)14752026/09/16 23:49:00 INFO Aborted multipart uploads count=014762026/09/16 23:49:00 OK 2_object_stats_trigger.sql (1.65ms)14772026/09/16 23:49:00 goose: up to current file version: 214782026/09/16 23:49:00 OK 1_commit_pending_closure.sql (3.05ms)1479--- PASS: TestMultipartCleanup (0.71s)1480=== CONT TestCacheStatsHandler14812026/09/16 23:49:00 WARN Force mode enabled - objects will be deleted immediately without grace period14822026/09/16 23:49:00 OK 2_object_stats_trigger.sql (1.5ms)14832026/09/16 23:49:00 goose: up to current file version: 214842026/09/16 23:49:00 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=014852026/09/16 23:49:00 INFO Vacuumed table table=pending_closures14862026/09/16 23:49:00 INFO Vacuumed table table=pending_objects14872026/09/16 23:49:00 INFO Vacuumed table table=multipart_uploads14882026/09/16 23:49:00 INFO Vacuumed table table=closures14892026/09/16 23:49:00 INFO Vacuumed table table=objects14902026/09/16 23:49:00 OK 20241026095416_initial_model.sql (9.03ms)14912026/09/16 23:49:00 OK 20251210153512_drop_unused_gin_index.sql (1.35ms)14922026/09/16 23:49:00 OK 20251218171726_add_pins.sql (3.13ms)1493--- PASS: TestGCMetrics (0.57s)1494=== CONT TestClaim_FailWakesWaitersButIsNotRemembered14952026/09/16 23:49:00 OK 20260628120000_add_object_size_and_stats.sql (3.68ms)14962026/09/16 23:49:00 OK 20260905000000_add_claims.sql (3.54ms)14972026/09/16 23:49:00 goose: successfully migrated database to version: 2026090500000014982026/09/16 23:49:00 OK 1_commit_pending_closure.sql (11.6ms)1499--- PASS: TestService_healthCheckHandler (0.54s)1500=== CONT TestCacheConfigHandler1501=== RUN TestCacheConfigHandler/full_config,_no_issuer1502=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1503=== RUN TestCacheConfigHandler/no_cache_url_configured1504=== PAUSE TestCacheConfigHandler/no_cache_url_configured1505=== RUN TestCacheConfigHandler/no_signing_keys1506=== PAUSE TestCacheConfigHandler/no_signing_keys1507=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1508=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1509=== CONT TestClaim_HolderDisconnectKeepsClaim15102026/09/16 23:49:00 OK 2_object_stats_trigger.sql (2.54ms)15112026/09/16 23:49:00 goose: up to current file version: 215122026-09-16 23:49:00.533 UTC [809] ERROR: relation "goose_db_version" does not exist at character 3615132026-09-16 23:49:00.533 UTC [809] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15142026-09-16 23:49:00.545 UTC [811] ERROR: relation "goose_db_version" does not exist at character 3615152026-09-16 23:49:00.545 UTC [811] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15162026-09-16 23:49:00.546 UTC [812] ERROR: relation "goose_db_version" does not exist at character 3615172026-09-16 23:49:00.546 UTC [812] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15182026/09/16 23:49:00 OK 20241026095416_initial_model.sql (8.71ms)15192026/09/16 23:49:00 OK 20251210153512_drop_unused_gin_index.sql (2.02ms)15202026/09/16 23:49:00 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"15212026/09/16 23:49:00 OK 20251218171726_add_pins.sql (3.48ms)15222026/09/16 23:49:00 OK 20260628120000_add_object_size_and_stats.sql (3.74ms)15232026/09/16 23:49:00 OK 20241026095416_initial_model.sql (9.37ms)15242026/09/16 23:49:00 OK 20260905000000_add_claims.sql (3.31ms)15252026/09/16 23:49:00 goose: successfully migrated database to version: 2026090500000015262026/09/16 23:49:00 OK 20241026095416_initial_model.sql (9.79ms)15272026/09/16 23:49:00 OK 20251210153512_drop_unused_gin_index.sql (1.64ms)15282026/09/16 23:49:00 OK 20251210153512_drop_unused_gin_index.sql (1.74ms)15292026/09/16 23:49:00 OK 1_commit_pending_closure.sql (2.63ms)15302026/09/16 23:49:00 OK 2_object_stats_trigger.sql (1.92ms)15312026/09/16 23:49:00 goose: up to current file version: 215322026/09/16 23:49:00 OK 20251218171726_add_pins.sql (3.86ms)15332026/09/16 23:49:00 OK 20251218171726_add_pins.sql (3.64ms)15342026/09/16 23:49:00 OK 20260628120000_add_object_size_and_stats.sql (3.5ms)15352026/09/16 23:49:00 OK 20260628120000_add_object_size_and_stats.sql (3.66ms)15362026/09/16 23:49:00 OK 20260905000000_add_claims.sql (3.17ms)15372026/09/16 23:49:00 goose: successfully migrated database to version: 2026090500000015382026/09/16 23:49:00 OK 20260905000000_add_claims.sql (3.31ms)15392026/09/16 23:49:00 goose: successfully migrated database to version: 2026090500000015402026/09/16 23:49:00 OK 1_commit_pending_closure.sql (2.29ms)15412026/09/16 23:49:00 OK 1_commit_pending_closure.sql (2.1ms)15422026/09/16 23:49:00 OK 2_object_stats_trigger.sql (1.61ms)15432026/09/16 23:49:00 goose: up to current file version: 215442026/09/16 23:49:00 OK 2_object_stats_trigger.sql (1.66ms)15452026/09/16 23:49:00 goose: up to current file version: 215462026/09/16 23:49:00 INFO Received uploads request method=POST path=/api/pending_closures15472026-09-16 23:49:00.588 UTC [866] ERROR: relation "goose_db_version" does not exist at character 3615482026-09-16 23:49:00.588 UTC [866] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15492026/09/16 23:49:00 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15502026/09/16 23:49:00 INFO Uploading bsj3kyn585dgqk3ac4nf8k0ysgw56b5r-file1.txt (160B)15512026/09/16 23:49:00 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"15522026/09/16 23:49:00 OK 20241026095416_initial_model.sql (8.19ms)15532026/09/16 23:49:00 OK 20251210153512_drop_unused_gin_index.sql (2.19ms)15542026/09/16 23:49:00 WARN Failed to register uploaded object key=bsj3kyn585dgqk3ac4nf8k0ysgw56b5r.ls error="server returned 404: 404 page not found\n"15552026/09/16 23:49:00 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign15562026/09/16 23:49:00 INFO Signed narinfos id=1 count=115572026/09/16 23:49:00 INFO Uploading 1 narinfos15582026/09/16 23:49:00 OK 20251218171726_add_pins.sql (2.67ms)15592026/09/16 23:49:00 OK 20260628120000_add_object_size_and_stats.sql (2.55ms)15602026/09/16 23:49:00 WARN Failed to register uploaded object key=bsj3kyn585dgqk3ac4nf8k0ysgw56b5r.narinfo error="server returned 404: 404 page not found\n"15612026/09/16 23:49:00 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete15622026-09-16 23:49:00.612 UTC [885] ERROR: relation "goose_db_version" does not exist at character 3615632026-09-16 23:49:00.612 UTC [885] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15642026/09/16 23:49:00 OK 20260905000000_add_claims.sql (2.52ms)15652026/09/16 23:49:00 goose: successfully migrated database to version: 2026090500000015662026/09/16 23:49:00 INFO Received complete multipart upload request method=POST path=/api/multipart/complete15672026/09/16 23:49:00 OK 1_commit_pending_closure.sql (1.48ms)15682026/09/16 23:49:00 OK 2_object_stats_trigger.sql (722.85µs)15692026/09/16 23:49:00 goose: up to current file version: 215702026/09/16 23:49:00 INFO Completed upload id=115712026/09/16 23:49:00 INFO Upload complete. (103ms)1572=== NAME TestNARDeduplicationMetadataUploadBug1573 metadata_upload_test.go:54: Retrieved narinfo from S3:1574 StorePath: /build/TestNARDeduplicationMetadataUploadBug4061835413/001/store/bsj3kyn585dgqk3ac4nf8k0ysgw56b5r-file1.txt1575 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1576 Compression: zstd1577 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1578 NarSize: 1601579 References: 1580 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1581 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1582 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1583 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}15842026-09-16 23:49:00.624 UTC [888] ERROR: relation "goose_db_version" does not exist at character 3615852026-09-16 23:49:00.624 UTC [888] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1586=== NAME TestPinProtectsFromGC1587 client_integration_test.go:667: Pinned store path: /build/TestPinProtectsFromGC589439864/001/store/l4k1zaz04nhb18p9jkpdg5c9nww4h4xa-pinned-file.txt1588 client_integration_test.go:668: Unpinned store path: /build/TestPinProtectsFromGC589439864/001/store/56y871njkng0gdwr6m16pbfmbdjm8wbw-unpinned-file.txt15892026/09/16 23:49:00 OK 20241026095416_initial_model.sql (14.48ms)15902026/09/16 23:49:00 OK 20251210153512_drop_unused_gin_index.sql (1.64ms)15912026/09/16 23:49:00 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=N2JlMDI3ZjMtODc4Ny00MjgyLWJjMzUtYzRlM2M4ZWJhN2I1LjdlOTgzN2ZkLTJjYmMtNDY4ZS1hOGFkLWI0Mjg5NjEzZTBmM3gxNzg5NjAyNTQwMTI5MjIzNzQ4 parts=1215922026/09/16 23:49:00 INFO Received uploads request method=POST path=/api/pending_closures15932026/09/16 23:49:00 OK 20251218171726_add_pins.sql (2.77ms)1594--- PASS: TestCompletedNarNotReofferedAcrossClosures (1.28s)1595=== CONT TestService_ReadAuthMiddleware1596=== NAME TestOrphanedObjectsGC1597 orphaned_objects_gc_test.go:290: GC Test Summary:1598 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A1599 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B1600 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)1601 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)1602 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects1603--- PASS: TestOrphanedObjectsGC (0.95s)1604=== CONT TestService_RequireScope_OIDC16052026/09/16 23:49:00 OK 20260628120000_add_object_size_and_stats.sql (2.49ms)16062026/09/16 23:49:00 OK 20241026095416_initial_model.sql (6.68ms)16072026/09/16 23:49:00 OK 20251210153512_drop_unused_gin_index.sql (949.13µs)16082026/09/16 23:49:00 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:36121/oidc16092026/09/16 23:49:00 OK 20260905000000_add_claims.sql (2ms)16102026/09/16 23:49:00 goose: successfully migrated database to version: 202609050000001611=== NAME TestClientMultipleUploads1612 client_integration_test.go:358: Created store path 0: /build/TestClientMultipleUploads590028559/001/store/l5wbfpkx0ys8w9v538rgawgp7s22d5dc-test-file-0.txt16132026/09/16 23:49:00 OK 20251218171726_add_pins.sql (2.03ms)16142026/09/16 23:49:00 OK 1_commit_pending_closure.sql (1.68ms)16152026/09/16 23:49:00 OK 2_object_stats_trigger.sql (656.52µs)16162026/09/16 23:49:00 goose: up to current file version: 216172026/09/16 23:49:00 OK 20260628120000_add_object_size_and_stats.sql (2.04ms)16182026/09/16 23:49:00 OK 20260905000000_add_claims.sql (1.84ms)16192026/09/16 23:49:00 goose: successfully migrated database to version: 2026090500000016202026/09/16 23:49:00 OK 1_commit_pending_closure.sql (1.38ms)16212026/09/16 23:49:00 OK 2_object_stats_trigger.sql (648.78µs)16222026/09/16 23:49:00 goose: up to current file version: 21623=== NAME TestNARDeduplicationMetadataUploadBug1624 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug4061835413/001/store/8cib9svp4cddxn0wvpn66jx42agyi7xs-file2.txt1625=== NAME TestClientWithDependencies1626 client_integration_test.go:613: Built derivation: /build/TestClientWithDependencies426978269/001/store/2jjc64r3rzga4wvw6wmyp4x6l29z13gi-test-script1627=== NAME TestClientIntegration1628 client_integration_test.go:286: Created store path: /build/TestClientIntegration3942884382/002/store/b52jcq733i8x6say6zjplnlhrmmn2f38-test-file.txt16292026/09/16 23:49:00 WARN claim: cannot clear write deadline error="feature not supported"1630=== NAME TestClientMultipleUploads1631 client_integration_test.go:358: Created store path 1: /build/TestClientMultipleUploads590028559/001/store/69llgwhkn8a92icgnadjk8rzc3mq6916-test-file-1.txt1632--- PASS: TestClaim_TooManyStreams (0.54s)1633=== CONT TestService_AuthMiddleware_OIDC16342026/09/16 23:49:00 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:36173/oidc16352026/09/16 23:49:00 INFO Received uploads request method=POST path=/api/pending_closures1636=== NAME TestClientWithDependencies1637 client_integration_test.go:615: Found 1 dependencies (including self)16382026/09/16 23:49:00 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"1639=== NAME TestClientMultipleUploads1640 client_integration_test.go:358: Created store path 2: /build/TestClientMultipleUploads590028559/001/store/w2kb3a3285qbvpzm0w2jbl0iddmh0l5i-test-file-2.txt16412026/09/16 23:49:00 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"16422026-09-16 23:49:00.724 UTC [1161] ERROR: relation "goose_db_version" does not exist at character 3616432026-09-16 23:49:00.724 UTC [1161] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16442026-09-16 23:49:00.730 UTC [1165] ERROR: relation "goose_db_version" does not exist at character 3616452026-09-16 23:49:00.730 UTC [1165] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16462026/09/16 23:49:00 OK 20241026095416_initial_model.sql (7.21ms)16472026/09/16 23:49:00 INFO Received uploads request method=POST path=/api/pending_closures16482026/09/16 23:49:00 OK 20251210153512_drop_unused_gin_index.sql (878.1µs)1649--- PASS: TestService_ReadScope_PublicByDefault (0.43s)1650=== CONT TestService_AuthMiddleware_MTLSBoundSubjects16512026/09/16 23:49:00 OK 20251218171726_add_pins.sql (2.53ms)16522026/09/16 23:49:00 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)1653--- PASS: TestGCBugBareHashReferences (0.78s)16542026/09/16 23:49:00 INFO Uploading l4k1zaz04nhb18p9jkpdg5c9nww4h4xa-pinned-file.txt (128B)1655=== CONT TestService_AuthMiddleware_MTLSProxyHeader16562026/09/16 23:49:00 OK 20241026095416_initial_model.sql (7.43ms)16572026/09/16 23:49:00 OK 20260628120000_add_object_size_and_stats.sql (3.19ms)16582026/09/16 23:49:00 OK 20251210153512_drop_unused_gin_index.sql (1.4ms)16592026/09/16 23:49:00 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"16602026/09/16 23:49:00 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"16612026/09/16 23:49:00 OK 20260905000000_add_claims.sql (2.62ms)16622026/09/16 23:49:00 goose: successfully migrated database to version: 2026090500000016632026/09/16 23:49:00 OK 20251218171726_add_pins.sql (2.34ms)16642026/09/16 23:49:00 OK 1_commit_pending_closure.sql (1.75ms)16652026/09/16 23:49:00 WARN Failed to register uploaded object key=l4k1zaz04nhb18p9jkpdg5c9nww4h4xa.ls error="server returned 404: 404 page not found\n"16662026/09/16 23:49:00 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign16672026/09/16 23:49:00 INFO Signed narinfos id=1 count=116682026/09/16 23:49:00 INFO Uploading 1 narinfos16692026/09/16 23:49:00 OK 2_object_stats_trigger.sql (1.3ms)16702026/09/16 23:49:00 goose: up to current file version: 216712026/09/16 23:49:00 OK 20260628120000_add_object_size_and_stats.sql (3.31ms)16722026/09/16 23:49:00 WARN Failed to register uploaded object key=l4k1zaz04nhb18p9jkpdg5c9nww4h4xa.narinfo error="server returned 404: 404 page not found\n"16732026/09/16 23:49:00 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete1674=== NAME TestClientCADerivations1675 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations609631504/001/store/16bkl6i2lnskmmjwn4bf2dai1ddz4afz-ca-test16762026/09/16 23:49:00 OK 20260905000000_add_claims.sql (2.56ms)16772026/09/16 23:49:00 goose: successfully migrated database to version: 2026090500000016782026/09/16 23:49:00 INFO Received uploads request method=POST path=/api/pending_closures16792026/09/16 23:49:00 OK 1_commit_pending_closure.sql (1.64ms)16802026/09/16 23:49:00 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)16812026/09/16 23:49:00 OK 2_object_stats_trigger.sql (1.56ms)16822026/09/16 23:49:00 goose: up to current file version: 216832026/09/16 23:49:00 INFO Completed upload id=116842026/09/16 23:49:00 INFO Upload complete. (95ms)16852026/09/16 23:49:00 WARN Failed to register uploaded object key=8cib9svp4cddxn0wvpn66jx42agyi7xs.ls error="server returned 404: 404 page not found\n"16862026/09/16 23:49:00 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign16872026/09/16 23:49:00 INFO Signed narinfos id=2 count=116882026/09/16 23:49:00 INFO Uploading 1 narinfos16892026/09/16 23:49:00 WARN claim: cannot clear write deadline error="feature not supported"16902026/09/16 23:49:00 WARN Failed to register uploaded object key=8cib9svp4cddxn0wvpn66jx42agyi7xs.narinfo error="server returned 404: 404 page not found\n"16912026/09/16 23:49:00 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete16922026/09/16 23:49:00 INFO Completed upload id=216932026/09/16 23:49:00 INFO Upload complete. (79ms)1694=== NAME TestNARDeduplicationMetadataUploadBug1695 metadata_upload_test.go:76: Retrieved narinfo from S3:1696 StorePath: /build/TestNARDeduplicationMetadataUploadBug4061835413/001/store/8cib9svp4cddxn0wvpn66jx42agyi7xs-file2.txt1697 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1698 Compression: zstd1699 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1700 NarSize: 1601701 References: 1702 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1703 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1704 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1705 {"version":1,"root":{"type":"regular","size":44}}1706--- PASS: TestNARDeduplicationMetadataUploadBug (0.89s)1707=== CONT TestProxyWriteTimeout/narinfo1708=== CONT TestProxyWriteTimeout/unknown_size1709=== CONT TestProxyWriteTimeout/10_GiB_nar1710=== CONT TestProxyWriteTimeout/1_GiB_nar1711--- PASS: TestProxyWriteTimeout (0.00s)1712 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1713 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1714 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1715 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1716=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info17172026/09/16 23:49:00 INFO Received uploads request method=POST path=/1718=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key17192026/09/16 23:49:00 INFO Received request for more parts method=POST path=/1720=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key17212026/09/16 23:49:00 INFO Received complete multipart upload request method=POST path=/1722=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal17232026/09/16 23:49:00 INFO Received uploads request method=POST path=/1724--- PASS: TestUploadHandlersRejectInvalidKeys (0.07s)1725 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1726 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1727 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1728 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1729=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure17302026/09/16 23:49:00 INFO Received uploads request method=POST path=/17312026/09/16 23:49:00 WARN claim: cannot clear write deadline error="feature not supported"17322026/09/16 23:49:00 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"17332026/09/16 23:49:00 INFO Received uploads request method=POST path=/api/pending_closures17342026/09/16 23:49:00 WARN claim: cannot clear write deadline error="feature not supported"17352026/09/16 23:49:00 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"17362026/09/16 23:49:00 INFO Received uploads request method=POST path=/api/pending_closures17372026-09-16 23:49:00.782 UTC [1333] ERROR: relation "goose_db_version" does not exist at character 3617382026-09-16 23:49:00.782 UTC [1333] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17392026/09/16 23:49:00 INFO Received uploads request method=POST path=/api/pending_closures17402026/09/16 23:49:00 INFO Received uploads request method=POST path=/api/pending_closures1741=== NAME TestClientCADerivations1742 client_ca_test.go:139: Found 1 dependencies (including self)17432026/09/16 23:49:00 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)17442026/09/16 23:49:00 INFO Uploading b52jcq733i8x6say6zjplnlhrmmn2f38-test-file.txt (152B)17452026/09/16 23:49:00 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)17462026/09/16 23:49:00 INFO Uploading 2jjc64r3rzga4wvw6wmyp4x6l29z13gi-test-script (136B)17472026/09/16 23:49:00 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"17482026/09/16 23:49:00 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"17492026/09/16 23:49:00 OK 20241026095416_initial_model.sql (10.89ms)17502026/09/16 23:49:00 WARN Failed to register uploaded object key=log/sfdni53s7bpvwcnf7igvxns8y7ksylw5-test-script.drv error="server returned 404: 404 page not found\n"17512026/09/16 23:49:00 WARN Failed to register uploaded object key=2jjc64r3rzga4wvw6wmyp4x6l29z13gi.ls error="server returned 404: 404 page not found\n"17522026/09/16 23:49:00 OK 20251210153512_drop_unused_gin_index.sql (2.25ms)17532026/09/16 23:49:00 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign17542026/09/16 23:49:00 WARN Failed to register uploaded object key=b52jcq733i8x6say6zjplnlhrmmn2f38.ls error="server returned 404: 404 page not found\n"17552026/09/16 23:49:00 INFO Signed narinfos id=1 count=117562026/09/16 23:49:00 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign17572026/09/16 23:49:00 INFO Uploading 1 narinfos17582026/09/16 23:49:00 INFO Signed narinfos id=1 count=117592026/09/16 23:49:00 INFO Uploading 1 narinfos17602026/09/16 23:49:00 OK 20251218171726_add_pins.sql (2.71ms)17612026/09/16 23:49:00 WARN Failed to register uploaded object key=2jjc64r3rzga4wvw6wmyp4x6l29z13gi.narinfo error="server returned 404: 404 page not found\n"17622026/09/16 23:49:00 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete17632026/09/16 23:49:00 WARN Failed to register uploaded object key=b52jcq733i8x6say6zjplnlhrmmn2f38.narinfo error="server returned 404: 404 page not found\n"17642026/09/16 23:49:00 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete17652026/09/16 23:49:00 OK 20260628120000_add_object_size_and_stats.sql (3.76ms)17662026/09/16 23:49:00 INFO Received uploads request method=POST path=/api/pending_closures17672026/09/16 23:49:00 OK 20260905000000_add_claims.sql (2.99ms)17682026/09/16 23:49:00 goose: successfully migrated database to version: 2026090500000017692026/09/16 23:49:00 OK 1_commit_pending_closure.sql (1.91ms)17702026/09/16 23:49:00 OK 2_object_stats_trigger.sql (1.92ms)17712026/09/16 23:49:00 goose: up to current file version: 217722026/09/16 23:49:00 INFO Completed upload id=117732026/09/16 23:49:00 INFO Completed upload id=117742026/09/16 23:49:00 INFO Upload complete. (112ms)17752026/09/16 23:49:00 INFO Upload complete. (76ms)1776=== NAME TestClientWithDependencies1777 client_integration_test.go:617: Skipping nix copy test - isolated store (/build/TestClientWithDependencies426978269/001/store) requires matching store prefix17782026/09/16 23:49:00 INFO Received uploads request method=POST path=/api/pending_closures1779--- PASS: TestClientWithDependencies (0.76s)1780=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart17812026/09/16 23:49:00 INFO Received complete multipart upload request method=POST path=/17822026/09/16 23:49:00 INFO Received uploads request method=POST path=/api/pending_closures17832026/09/16 23:49:00 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"17842026/09/16 23:49:00 INFO Received uploads request method=POST path=/api/pending_closures17852026/09/16 23:49:00 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)17862026/09/16 23:49:00 INFO Uploading w2kb3a3285qbvpzm0w2jbl0iddmh0l5i-test-file-2.txt (160B)17872026/09/16 23:49:00 INFO Uploading l5wbfpkx0ys8w9v538rgawgp7s22d5dc-test-file-0.txt (160B)17882026/09/16 23:49:00 INFO Uploading 69llgwhkn8a92icgnadjk8rzc3mq6916-test-file-1.txt (160B)17892026/09/16 23:49:00 WARN claim: cannot clear write deadline error="feature not supported"17902026/09/16 23:49:00 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"17912026/09/16 23:49:00 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"17922026-09-16 23:49:00.838 UTC [1427] ERROR: relation "goose_db_version" does not exist at character 3617932026-09-16 23:49:00.838 UTC [1427] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17942026/09/16 23:49:00 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"17952026-09-16 23:49:00.839 UTC [1428] ERROR: relation "goose_db_version" does not exist at character 3617962026-09-16 23:49:00.839 UTC [1428] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17972026/09/16 23:49:00 WARN Failed to register uploaded object key=l5wbfpkx0ys8w9v538rgawgp7s22d5dc.ls error="server returned 404: 404 page not found\n"17982026/09/16 23:49:00 WARN Failed to register uploaded object key=w2kb3a3285qbvpzm0w2jbl0iddmh0l5i.ls error="server returned 404: 404 page not found\n"17992026/09/16 23:49:00 WARN Failed to register uploaded object key=69llgwhkn8a92icgnadjk8rzc3mq6916.ls error="server returned 404: 404 page not found\n"18002026/09/16 23:49:00 INFO Received sign narinfos request method=POST path=/api/pending_closures/3/sign18012026/09/16 23:49:00 INFO Signed narinfos id=3 count=118022026/09/16 23:49:00 WARN claim: cannot clear write deadline error="feature not supported"18032026/09/16 23:49:00 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign18042026/09/16 23:49:00 INFO Signed narinfos id=1 count=11805--- PASS: TestClaim_StaleHeartbeatStolen (0.41s)1806=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts18072026/09/16 23:49:00 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign18082026/09/16 23:49:00 INFO Received request for more parts method=POST path=/18092026/09/16 23:49:00 INFO Signed narinfos id=2 count=118102026/09/16 23:49:00 INFO Uploading 3 narinfos18112026/09/16 23:49:00 WARN Failed to register uploaded object key=w2kb3a3285qbvpzm0w2jbl0iddmh0l5i.narinfo error="server returned 404: 404 page not found\n"18122026/09/16 23:49:00 WARN Failed to register uploaded object key=l5wbfpkx0ys8w9v538rgawgp7s22d5dc.narinfo error="server returned 404: 404 page not found\n"18132026/09/16 23:49:00 WARN Failed to register uploaded object key=69llgwhkn8a92icgnadjk8rzc3mq6916.narinfo error="server returned 404: 404 page not found\n"18142026/09/16 23:49:00 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete18152026/09/16 23:49:00 OK 20241026095416_initial_model.sql (7.83ms)18162026/09/16 23:49:00 OK 20241026095416_initial_model.sql (8.07ms)18172026/09/16 23:49:00 INFO All 1 paths already cached18182026/09/16 23:49:00 OK 20251210153512_drop_unused_gin_index.sql (1.01ms)18192026/09/16 23:49:00 OK 20251210153512_drop_unused_gin_index.sql (994.72µs)1820=== NAME TestClientIntegration1821 client_integration_test.go:312: Retrieved narinfo from S3:1822 StorePath: /build/TestClientIntegration3942884382/002/store/b52jcq733i8x6say6zjplnlhrmmn2f38-test-file.txt1823 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst18242026/09/16 23:49:00 INFO Completed upload id=11825 Compression: zstd1826 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11827 NarSize: 1521828 References: 1829 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk118302026/09/16 23:49:00 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete18312026/09/16 23:49:00 INFO Completed upload id=218322026/09/16 23:49:00 INFO Received complete upload request method=POST path=/api/pending_closures/3/complete18332026/09/16 23:49:00 OK 20251218171726_add_pins.sql (2.54ms)18342026/09/16 23:49:00 OK 20251218171726_add_pins.sql (2.29ms)18352026/09/16 23:49:00 INFO Completed upload id=318362026/09/16 23:49:00 INFO Upload complete. (114ms)1837=== NAME TestClientMultipleUploads1838 client_integration_test.go:369: Uploaded 3 paths in 147.162691ms1839=== NAME TestClientIntegration1840 client_integration_test.go:313: Retrieved .ls file from S3 (compressed size: 77 bytes)1841 client_integration_test.go:313: Decompressed .ls content (64 bytes):1842 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1843 client_integration_test.go:316: Testing garbage collection...18442026/09/16 23:49:00 WARN claim: cannot clear write deadline error="feature not supported"18452026/09/16 23:49:00 OK 20260628120000_add_object_size_and_stats.sql (3.22ms)18462026/09/16 23:49:00 OK 20260628120000_add_object_size_and_stats.sql (3.41ms)18472026/09/16 23:49:00 OK 20260905000000_add_claims.sql (2.51ms)18482026/09/16 23:49:00 goose: successfully migrated database to version: 2026090500000018492026/09/16 23:49:00 OK 20260905000000_add_claims.sql (2.68ms)18502026/09/16 23:49:00 goose: successfully migrated database to version: 202609050000001851=== CONT TestIsValidUploadKey/narinfo1852=== CONT TestIsValidUploadKey/realisation_plus_in_output1853=== CONT TestIsValidUploadKey/unknown_type1854=== CONT TestIsValidUploadKey/empty_key1855=== CONT TestIsValidUploadKey/absolute1856=== CONT TestIsValidUploadKey/traversal_nar1857=== CONT TestIsValidUploadKey/traversal1858=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1859=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1860=== CONT TestIsValidUploadKey/nix-cache-info1861=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1862=== CONT TestIsValidUploadKey/index.html1863=== CONT TestIsValidUploadKey/build_log_home-manager_file1864=== CONT TestIsValidUploadKey/nar_plain1865=== CONT TestIsValidUploadKey/realisation1866=== CONT TestIsValidUploadKey/build_log1867=== CONT TestIsValidUploadKey/build_log_equals1868=== CONT TestIsValidUploadKey/listing1869=== CONT TestIsValidUploadKey/build_log_question_mark1870=== CONT TestIsValidUploadKey/build_log_plus_in_name1871=== CONT TestIsValidUploadKey/nar_xz1872=== CONT TestIsValidUploadKey/nar_zst1873--- PASS: TestIsValidUploadKey (0.15s)1874 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1875 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1876 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1877 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1878 --- PASS: TestIsValidUploadKey/absolute (0.00s)1879 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1880 --- PASS: TestIsValidUploadKey/traversal (0.00s)1881 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1882 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1883 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1884 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1885 --- PASS: TestIsValidUploadKey/index.html (0.00s)1886 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1887 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1888 --- PASS: TestIsValidUploadKey/realisation (0.00s)1889 --- PASS: TestIsValidUploadKey/build_log (0.00s)1890 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1891 --- PASS: TestIsValidUploadKey/listing (0.00s)1892 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1893 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1894 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1895 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1896=== CONT TestIsValidCachePath/narinfo1897=== CONT TestIsValidCachePath/index.html1898=== CONT TestIsValidCachePath/short_hash1899=== CONT TestIsValidCachePath/wrong_extension1900=== CONT TestIsValidCachePath/leading_slash1901=== CONT TestIsValidCachePath/empty1902=== CONT TestIsValidCachePath/traversal_in_middle19032026/09/16 23:49:00 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"1904=== CONT TestIsValidCachePath/traversal_parent1905=== CONT TestIsValidCachePath/nar_uncompressed1906=== CONT TestIsValidCachePath/nix-cache-info1907=== CONT TestIsValidCachePath/realisation1908=== CONT TestIsValidCachePath/log19092026/09/16 23:49:00 OK 1_commit_pending_closure.sql (1.34ms)1910=== CONT TestIsValidCachePath/invalid_char_e1911=== CONT TestIsValidCachePath/ls1912=== CONT TestIsValidCachePath/random_path1913=== CONT TestIsValidCachePath/nar_xz1914=== CONT TestIsValidCachePath/invalid_char_u1915=== CONT TestIsValidCachePath/nar_bz21916=== CONT TestIsValidCachePath/nar_zst1917=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1918--- PASS: TestIsValidCachePath (0.00s)1919 --- PASS: TestIsValidCachePath/narinfo (0.00s)1920 --- PASS: TestIsValidCachePath/index.html (0.00s)1921 --- PASS: TestIsValidCachePath/short_hash (0.00s)1922 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1923 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1924 --- PASS: TestIsValidCachePath/empty (0.00s)1925 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1926 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1927 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1928 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1929 --- PASS: TestIsValidCachePath/realisation (0.00s)1930 --- PASS: TestIsValidCachePath/log (0.00s)1931 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1932 --- PASS: TestIsValidCachePath/ls (0.00s)1933 --- PASS: TestIsValidCachePath/random_path (0.00s)1934 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1935 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1936 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1937 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1938 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1939=== CONT TestParseSingleRange/none1940=== CONT TestParseSingleRange/open-ended1941=== CONT TestParseSingleRange/start_far_past_EOF1942=== CONT TestParseSingleRange/start_past_EOF1943=== CONT TestParseSingleRange/single_byte1944=== CONT TestParseSingleRange/suffix_exceeds_size1945=== CONT TestParseSingleRange/end_clamped_to_size1946=== CONT TestParseSingleRange/suffix1947=== CONT TestParseSingleRange/malformed_both_empty1948=== CONT TestParseSingleRange/closed1949=== CONT TestParseSingleRange/multi-range_ignored1950=== CONT TestParseSingleRange/malformed_end_before_start19512026/09/16 23:49:00 OK 1_commit_pending_closure.sql (1.63ms)1952=== CONT TestParseSingleRange/malformed_no_dash1953=== CONT TestParseSingleRange/unknown_unit1954--- PASS: TestParseSingleRange (0.00s)1955 --- PASS: TestParseSingleRange/none (0.00s)1956 --- PASS: TestParseSingleRange/open-ended (0.00s)1957 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1958 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1959 --- PASS: TestParseSingleRange/single_byte (0.00s)1960 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1961 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1962 --- PASS: TestParseSingleRange/suffix (0.00s)1963 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1964 --- PASS: TestParseSingleRange/closed (0.00s)1965 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1966 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1967 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1968 --- PASS: TestParseSingleRange/unknown_unit (0.00s)19692026/09/16 23:49:00 OK 2_object_stats_trigger.sql (629.65µs)1970=== CONT TestClientErrorHandling/InvalidStorePath19712026/09/16 23:49:00 goose: up to current file version: 219722026/09/16 23:49:00 OK 2_object_stats_trigger.sql (833.57µs)1973--- PASS: TestClientMultipleUploads (0.78s)19742026/09/16 23:49:00 goose: up to current file version: 21975=== CONT TestClientErrorHandling/ServerNotAvailable19762026/09/16 23:49:00 INFO Received uploads request method=POST path=/api/pending_closures19772026/09/16 23:49:00 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)19782026/09/16 23:49:00 INFO Uploading 56y871njkng0gdwr6m16pbfmbdjm8wbw-unpinned-file.txt (128B)19792026/09/16 23:49:00 WARN claim: cannot clear write deadline error="feature not supported"19802026/09/16 23:49:00 WARN claim: cannot clear write deadline error="feature not supported"19812026/09/16 23:49:00 INFO Received uploads request method=POST path=/api/pending_closures19822026/09/16 23:49:00 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"19832026/09/16 23:49:00 WARN Failed to register uploaded object key=56y871njkng0gdwr6m16pbfmbdjm8wbw.ls error="server returned 404: 404 page not found\n"19842026/09/16 23:49:00 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign19852026/09/16 23:49:00 INFO Signed narinfos id=2 count=119862026/09/16 23:49:00 INFO Uploading 1 narinfos19872026/09/16 23:49:00 WARN Failed to register uploaded object key=56y871njkng0gdwr6m16pbfmbdjm8wbw.narinfo error="server returned 404: 404 page not found\n"19882026/09/16 23:49:00 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete19892026/09/16 23:49:00 WARN claim: cannot clear write deadline error="feature not supported"19902026/09/16 23:49:00 INFO Completed upload id=219912026/09/16 23:49:00 INFO Upload complete. (91ms)19922026/09/16 23:49:00 WARN claim: cannot clear write deadline error="feature not supported"1993--- PASS: TestClaim_FailWithoutKindReleases (0.44s)1994=== CONT TestClientErrorHandling/InvalidAuthToken19952026/09/16 23:49:00 INFO Received uploads request method=POST path=/api/pending_closures19962026/09/16 23:49:00 INFO Starting cleanup of old closures method=DELETE path=/api/closures19972026/09/16 23:49:00 INFO Garbage collection started1998=== CONT TestServerTLSConfig/no_client_CA1999=== CONT TestServerTLSConfig/not_a_PEM_file20002026/09/16 23:49:00 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)20012026/09/16 23:49:00 INFO Uploading 16bkl6i2lnskmmjwn4bf2dai1ddz4afz-ca-test (144B)2002=== CONT TestServerTLSConfig/missing_CA_file2003--- PASS: TestServerTLSConfig (0.00s)2004 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)2005 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)2006 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)2007=== CONT TestResolveDBConnectionString/flag_wins2008=== CONT TestResolveDBConnectionString/PGHOST_allows_empty2009=== CONT TestResolveDBConnectionString/nothing_configured2010=== CONT TestResolveDBConnectionString/missing_file_is_an_error2011=== CONT TestResolveDBConnectionString/file_when_flag_empty2012=== CONT TestCacheConfigHandler/full_config,_no_issuer2013=== CONT TestCacheConfigHandler/no_signing_keys2014--- PASS: TestResolveDBConnectionString (0.00s)2015 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)2016 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)2017 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)2018 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)2019 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)2020=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator2021=== CONT TestCacheConfigHandler/no_cache_url_configured2022--- PASS: TestCacheConfigHandler (0.00s)2023 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)2024 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)2025 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)2026 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)20272026/09/16 23:49:00 INFO Aborted multipart uploads count=020282026/09/16 23:49:00 WARN Failed to register uploaded object key=log/ij7rplb7spmmq7jw4j7paf32msbxrg9x-ca-test.drv error="server returned 404: 404 page not found\n"20292026/09/16 23:49:00 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"20302026/09/16 23:49:00 WARN Force mode enabled - objects will be deleted immediately without grace period20312026/09/16 23:49:00 WARN Failed to register uploaded object key=16bkl6i2lnskmmjwn4bf2dai1ddz4afz.ls error="server returned 404: 404 page not found\n"20322026/09/16 23:49:00 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign20332026/09/16 23:49:00 INFO Signed narinfos id=1 count=120342026/09/16 23:49:00 INFO Uploading 1 narinfos20352026/09/16 23:49:00 WARN Failed to register uploaded object key=16bkl6i2lnskmmjwn4bf2dai1ddz4afz.narinfo error="server returned 404: 404 page not found\n"20362026/09/16 23:49:00 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete2037--- PASS: TestCacheStatsHandler (0.43s)20382026/09/16 23:49:00 INFO Received create pin request method=POST path=/api/pins/myapp20392026/09/16 23:49:00 INFO Completed upload id=120402026/09/16 23:49:00 INFO Upload complete. (100ms)20412026/09/16 23:49:00 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC589439864/001/store/l4k1zaz04nhb18p9jkpdg5c9nww4h4xa-pinned-file.txt narinfo_key=l4k1zaz04nhb18p9jkpdg5c9nww4h4xa.narinfo2042=== NAME TestClientCADerivations2043 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations609631504/001/store/16bkl6i2lnskmmjwn4bf2dai1ddz4afz-ca-test2044 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst2045 Compression: zstd2046 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n2047 NarSize: 1442048 References: 2049 Deriver: /build/TestClientCADerivations609631504/001/store/ij7rplb7spmmq7jw4j7paf32msbxrg9x-ca-test.drv2050 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n2051 client_ca_test.go:185: Checking for realisation files in S3...20522026/09/16 23:49:00 INFO Starting cleanup of old closures method=DELETE path=/api/closures2053 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations2054 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache20552026/09/16 23:49:00 INFO Garbage collection started20562026/09/16 23:49:00 WARN claim: cannot clear write deadline error="feature not supported"20572026/09/16 23:49:00 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present20582026/09/16 23:49:00 WARN claim: cannot clear write deadline error="feature not supported"20592026/09/16 23:49:00 INFO Aborted multipart uploads count=020602026/09/16 23:49:00 WARN claim: cannot clear write deadline error="feature not supported"2061--- PASS: TestClaim_FailWakesWaitersButIsNotRemembered (0.43s)20622026/09/16 23:49:00 WARN Force mode enabled - objects will be deleted immediately without grace period20632026/09/16 23:49:00 WARN claim: cannot clear write deadline error="feature not supported"20642026-09-16 23:49:00.953 UTC [1580] ERROR: relation "goose_db_version" does not exist at character 3620652026-09-16 23:49:00.953 UTC [1580] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC20662026/09/16 23:49:00 WARN claim: cannot clear write deadline error="feature not supported"20672026/09/16 23:49:00 OK 20241026095416_initial_model.sql (7.76ms)20682026/09/16 23:49:00 OK 20251210153512_drop_unused_gin_index.sql (859.99µs)20692026/09/16 23:49:00 OK 20251218171726_add_pins.sql (2.34ms)20702026/09/16 23:49:00 OK 20260628120000_add_object_size_and_stats.sql (2.82ms)20712026/09/16 23:49:00 OK 20260905000000_add_claims.sql (2.75ms)20722026/09/16 23:49:00 goose: successfully migrated database to version: 202609050000002073--- PASS: TestService_ReadAuthMiddleware (0.34s)20742026/09/16 23:49:00 OK 1_commit_pending_closure.sql (1.58ms)20752026/09/16 23:49:00 OK 2_object_stats_trigger.sql (708.69µs)20762026/09/16 23:49:00 goose: up to current file version: 220772026-09-16 23:49:00.979 UTC [1600] ERROR: relation "goose_db_version" does not exist at character 3620782026-09-16 23:49:00.979 UTC [1600] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC20792026/09/16 23:49:00 OK 20241026095416_initial_model.sql (7.27ms)20802026/09/16 23:49:00 OK 20251210153512_drop_unused_gin_index.sql (830.69µs)20812026/09/16 23:49:00 OK 20251218171726_add_pins.sql (1.99ms)20822026/09/16 23:49:00 OK 20260628120000_add_object_size_and_stats.sql (2.13ms)20832026/09/16 23:49:00 OK 20260905000000_add_claims.sql (2.54ms)20842026/09/16 23:49:00 goose: successfully migrated database to version: 2026090500000020852026/09/16 23:49:01 OK 1_commit_pending_closure.sql (1.52ms)20862026/09/16 23:49:01 OK 2_object_stats_trigger.sql (683.82µs)20872026/09/16 23:49:01 goose: up to current file version: 22088=== RUN TestService_RequireScope_OIDC/builder_may_write2089=== PAUSE TestService_RequireScope_OIDC/builder_may_write2090=== RUN TestService_RequireScope_OIDC/builder_may_not_admin2091=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin2092=== RUN TestService_RequireScope_OIDC/ops_may_admin2093=== PAUSE TestService_RequireScope_OIDC/ops_may_admin2094=== RUN TestService_RequireScope_OIDC/ops_may_not_write2095=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write2096=== RUN TestService_RequireScope_OIDC/reader_may_not_write2097=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write2098=== RUN TestService_RequireScope_OIDC/static_token_may_admin2099=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin2100=== RUN TestService_RequireScope_OIDC/static_token_may_write2101=== PAUSE TestService_RequireScope_OIDC/static_token_may_write2102=== RUN TestService_RequireScope_OIDC/reader_may_read2103=== PAUSE TestService_RequireScope_OIDC/reader_may_read2104=== RUN TestService_RequireScope_OIDC/writer_implies_read2105=== PAUSE TestService_RequireScope_OIDC/writer_implies_read2106=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read2107=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read2108=== CONT TestService_RequireScope_OIDC/builder_may_write2109=== CONT TestService_RequireScope_OIDC/static_token_may_admin2110=== CONT TestService_RequireScope_OIDC/static_token_may_write2111=== CONT TestService_RequireScope_OIDC/ops_may_admin2112=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read2113=== CONT TestService_RequireScope_OIDC/builder_may_not_admin2114=== CONT TestService_RequireScope_OIDC/writer_implies_read2115=== CONT TestService_RequireScope_OIDC/reader_may_read21162026/09/16 23:49:01 INFO OIDC auth successful provider=test scopes=[read]2117=== CONT TestService_RequireScope_OIDC/ops_may_not_write21182026/09/16 23:49:01 INFO OIDC auth successful provider=test scopes=[write]21192026/09/16 23:49:01 INFO OIDC auth successful provider=test scopes=[admin]2120=== CONT TestService_RequireScope_OIDC/reader_may_not_write21212026/09/16 23:49:01 INFO OIDC auth successful provider=test scopes=[write]21222026/09/16 23:49:01 INFO OIDC auth successful provider=test scopes=[admin]21232026/09/16 23:49:01 INFO OIDC auth successful provider=test scopes=[write]21242026/09/16 23:49:01 INFO OIDC auth successful provider=test scopes=[read]2125--- PASS: TestService_RequireScope_OIDC (0.37s)2126 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)2127 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)2128 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)2129 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)2130 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)2131 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)2132 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)2133 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)2134 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)2135 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)2136=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token2137=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token2138=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected2139=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected2140=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected2141=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected2142=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2143=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2144=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token2145=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected2146=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured21472026/09/16 23:49:01 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]2148=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected21492026/09/16 23:49:01 WARN Authentication failed token_preview=eyJhbGciOi...7VHcT_lfeQ token_length=702 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]21502026/09/16 23:49:01 INFO OIDC auth successful provider=test scopes=[write]2151--- PASS: TestService_AuthMiddleware_OIDC (0.34s)2152 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)2153 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)2154 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)2155 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)21562026/09/16 23:49:01 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=215.573131ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present21572026/09/16 23:49:01 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"21582026/09/16 23:49:01 WARN mTLS auth: bound subjects configured but subject DN unavailable21592026/09/16 23:49:01 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"2160--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (0.31s)2161--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.34s)2162=== NAME TestClientCADerivations2163 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features2164 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable2165 error: binary cache 's3://bucket43?endpoint=http://localhost:35937®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations609631504/001/store'2166 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 12167--- PASS: TestClientCADerivations (0.95s)21682026/09/16 23:49:01 INFO Received complete multipart upload request method=POST path=/api/multipart/complete21692026/09/16 23:49:01 INFO Completed multipart upload object_key=nar/0000000000000000000000000000002000000000000000000000.nar.zst upload_id=N2JlMDI3ZjMtODc4Ny00MjgyLWJjMzUtYzRlM2M4ZWJhN2I1LjFlMDE4NzYxLTQxNDAtNGVmOS05NWNjLTIwZjgxYzA1MTU4NXgxNzg5NjAyNTQwNzExODE4ODI1 parts=1021702026/09/16 23:49:01 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete21712026/09/16 23:49:01 INFO Completed upload id=121722026/09/16 23:49:01 INFO Received uploads request method=POST path=/api/pending_closures21732026/09/16 23:49:01 INFO Received complete multipart upload request method=POST path=/api/multipart/complete21742026/09/16 23:49:01 INFO Completed multipart upload object_key=nar/0000000000000000000000000000001600000000000000000000.nar.zst upload_id=N2JlMDI3ZjMtODc4Ny00MjgyLWJjMzUtYzRlM2M4ZWJhN2I1LjA2YzE0NGMxLTMxYTctNDA5OS05NGQzLTdmMzIyMjZjM2VkZXgxNzg5NjAyNTQwNzg4MDQyOTE5 parts=1021752026/09/16 23:49:01 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign21762026/09/16 23:49:01 INFO Signed narinfos id=1 count=121772026/09/16 23:49:01 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete21782026/09/16 23:49:01 INFO Completed upload id=12179--- PASS: TestClaim_TwoInstances (0.80s)21802026/09/16 23:49:01 INFO Received complete multipart upload request method=POST path=/api/multipart/complete21812026/09/16 23:49:01 INFO Received complete multipart upload request method=POST path=/api/multipart/complete21822026/09/16 23:49:01 INFO Completed multipart upload object_key=nar/0000000000000000000000000000001700000000000000000000.nar.zst upload_id=N2JlMDI3ZjMtODc4Ny00MjgyLWJjMzUtYzRlM2M4ZWJhN2I1LmU4ZmZmMzBjLWZmMGEtNGJjZC05NTU2LTVlNmI5NmVjMjgyOHgxNzg5NjAyNTQwODA0MzkyODEx parts=1021832026/09/16 23:49:01 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete21842026/09/16 23:49:01 INFO Completed upload id=121852026/09/16 23:49:01 WARN claim: cannot clear write deadline error="feature not supported"21862026/09/16 23:49:01 INFO Completed multipart upload object_key=nar/0000000000000000000000000000001100000000000000000000.nar.zst upload_id=N2JlMDI3ZjMtODc4Ny00MjgyLWJjMzUtYzRlM2M4ZWJhN2I1LmEyZDRmZGFhLTcyZjMtNDFlMi1hN2FjLTdkYTFhMDRjYmIyZXgxNzg5NjAyNTQwODI1NDk0NzYx parts=1021872026/09/16 23:49:01 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete21882026/09/16 23:49:01 INFO Completed upload id=121892026/09/16 23:49:01 WARN claim: cannot clear write deadline error="feature not supported"21902026/09/16 23:49:01 WARN claim: cannot clear write deadline error="feature not supported"21912026/09/16 23:49:01 INFO Aborted multipart uploads count=02192--- PASS: TestClaim_GCMarkedOutputCountsAsAbsent (0.81s)21932026/09/16 23:49:01 WARN Force mode enabled - objects will be deleted immediately without grace period21942026/09/16 23:49:01 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"21952026/09/16 23:49:01 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=021962026/09/16 23:49:01 INFO Vacuumed table table=pending_closures21972026/09/16 23:49:01 INFO Vacuumed table table=pending_objects21982026/09/16 23:49:01 INFO Vacuumed table table=multipart_uploads21992026/09/16 23:49:01 INFO Vacuumed table table=closures22002026/09/16 23:49:01 INFO Vacuumed table table=objects2201--- PASS: TestClaim_InputsTouched (0.85s)22022026/09/16 23:49:01 INFO Received complete multipart upload request method=POST path=/api/multipart/complete22032026/09/16 23:49:01 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"22042026/09/16 23:49:01 INFO Completed multipart upload object_key=nar/0000000000000000000000000000001000000000000000000000.nar.zst upload_id=N2JlMDI3ZjMtODc4Ny00MjgyLWJjMzUtYzRlM2M4ZWJhN2I1LjAxMjU0NmRkLWY5MDEtNDUwMy05YWFkLTY5MjU1MDdkYjRhZXgxNzg5NjAyNTQwODczMDgxNTY5 parts=1022052026/09/16 23:49:01 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign22062026/09/16 23:49:01 INFO Signed narinfos id=1 count=122072026/09/16 23:49:01 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete22082026/09/16 23:49:01 INFO Received uploads request method=POST path=/api/pending_closures22092026/09/16 23:49:01 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign22102026/09/16 23:49:01 INFO Signed narinfos id=2 count=122112026/09/16 23:49:01 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete22122026/09/16 23:49:01 INFO Completed upload id=222132026/09/16 23:49:01 WARN claim: cannot clear write deadline error="feature not supported"2214--- PASS: TestClaim_BuildWaitComplete (0.80s)22152026/09/16 23:49:01 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=405.719128ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present22162026/09/16 23:49:01 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"2217--- PASS: TestUploadHandlersRejectOversizedBody (0.15s)2218 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.04s)2219 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.06s)2220 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.62s)22212026/09/16 23:49:01 WARN claim: cannot clear write deadline error="feature not supported"22222026/09/16 23:49:01 INFO Received complete multipart upload request method=POST path=/api/multipart/complete22232026/09/16 23:49:01 INFO Completed multipart upload object_key=nar/0000000000000000000000000000002100000000000000000000.nar.zst upload_id=N2JlMDI3ZjMtODc4Ny00MjgyLWJjMzUtYzRlM2M4ZWJhN2I1Ljc1M2JkOGRjLTdmM2ItNGZjNy1iMGIyLTQ1NDc3YTUyZjkxZHgxNzg5NjAyNTQxMTE5NzM4NDIz parts=1022242026/09/16 23:49:01 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete22252026/09/16 23:49:01 INFO Completed upload id=22226--- PASS: TestPresent (1.36s)22272026/09/16 23:49:01 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=741.277801ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2228=== NAME TestOrphanedObjectsGCStressTest2229 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains2230 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion22312026/09/16 23:49:01 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=022322026/09/16 23:49:01 INFO Vacuumed table table=pending_closures22332026/09/16 23:49:01 INFO Vacuumed table table=pending_objects22342026/09/16 23:49:01 INFO Vacuumed table table=multipart_uploads22352026/09/16 23:49:01 INFO Vacuumed table table=closures22362026/09/16 23:49:01 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=022372026/09/16 23:49:01 INFO Vacuumed table table=objects22382026/09/16 23:49:01 INFO Vacuumed table table=pending_closures22392026/09/16 23:49:01 INFO Vacuumed table table=pending_objects22402026/09/16 23:49:01 INFO Vacuumed table table=multipart_uploads22412026/09/16 23:49:01 INFO Vacuumed table table=closures22422026/09/16 23:49:01 INFO Vacuumed table table=objects2243 orphaned_objects_gc_test.go:509: Stress test completed successfully:2244 orphaned_objects_gc_test.go:510: - Active objects preserved: 202245 orphaned_objects_gc_test.go:511: - Objects deleted: 2102246 orphaned_objects_gc_test.go:512: - Total GC'd: 2102247--- PASS: TestOrphanedObjectsGCStressTest (2.44s)2248--- PASS: TestClaim_StreamsThroughServer (2.01s)22492026/09/16 23:49:02 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.692943884s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present22502026/09/16 23:49:02 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=02251=== NAME TestClientIntegration2252 client_integration_test.go:323: Objects in database after GC:2253 client_integration_test.go:323: Successfully deleted all objects with GC --force2254--- PASS: TestClientIntegration (2.76s)22552026/09/16 23:49:02 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=02256=== NAME TestPinProtectsFromGC2257 client_integration_test.go:730: Pin successfully protected closure from garbage collection2258--- PASS: TestPinProtectsFromGC (2.90s)22592026/09/16 23:49:03 WARN Rate limiter enabled after throttle name=s3-test rate=522602026/09/16 23:49:03 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."2261=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle2262 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=102263 throttle_test.go:215: Rate limiter: enabled=true, rate=5.002264--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (3.95s)2265--- PASS: TestClaim_HolderDisconnectKeepsClaim (2.93s)22662026/09/16 23:49:04 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-config22672026/09/16 23:49:04 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=208.769307ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22682026/09/16 23:49:04 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=422.977731ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22692026/09/16 23:49:04 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=775.287107ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22702026/09/16 23:49:05 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.662439469s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22712026/09/16 23:49:07 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"22722026/09/16 23:49:07 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_closures22732026/09/16 23:49:07 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=199.826593ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22742026/09/16 23:49:07 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=437.093299ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22752026/09/16 23:49:08 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=723.589948ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22762026/09/16 23:49:08 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.631512061s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2277--- PASS: TestClientErrorHandling (0.00s)2278 --- PASS: TestClientErrorHandling/InvalidStorePath (0.27s)2279 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.38s)2280 --- PASS: TestClientErrorHandling/ServerNotAvailable (9.59s)2281PASS2282{"timestamp":"2026-09-16T23:49:10.454626342Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:45724","error_kind":"io_error","error":"Cancelled","result":"transport_error","target":"rustfs::server::http","filename":"rustfs/src/server/http.rs","line_number":1880,"threadName":"rustfs-worker","threadId":"ThreadId(386)"}22832026-09-16 23:49:10.750 UTC [129] LOG: received smart shutdown request22842026-09-16 23:49:10.755 UTC [129] LOG: background worker "logical replication launcher" (PID 139) exited with exit code 122852026-09-16 23:49:10.766 UTC [134] LOG: shutting down22862026-09-16 23:49:10.767 UTC [134] LOG: checkpoint starting: shutdown immediate22872026-09-16 23:49:12.473 UTC [134] LOG: checkpoint complete: wrote 10856 buffers (66.3%), wrote 3 SLRU buffers; 0 WAL file(s) added, 0 removed, 18 recycled; write=0.253 s, sync=1.432 s, total=1.708 s; sync files=21338, longest=0.012 s, average=0.001 s; distance=287443 kB, estimate=287443 kB; lsn=0/1301AA30, redo lsn=0/1301AA3022882026-09-16 23:49:12.554 UTC [129] LOG: database system is shut down2289Running OIDC tests...2290=== RUN TestGlobMatch2291=== PAUSE TestGlobMatch2292=== RUN TestAudienceForIssuer2293=== PAUSE TestAudienceForIssuer2294=== RUN TestValidateToken_ValidToken2295=== PAUSE TestValidateToken_ValidToken2296=== RUN TestValidateToken_WrongAudience2297=== PAUSE TestValidateToken_WrongAudience2298=== RUN TestValidateToken_Expired2299=== PAUSE TestValidateToken_Expired2300=== RUN TestValidateToken_BoundClaimsMismatch2301=== PAUSE TestValidateToken_BoundClaimsMismatch2302=== RUN TestValidateToken_BoundSubjectMismatch2303=== PAUSE TestValidateToken_BoundSubjectMismatch2304=== RUN TestValidateToken_MultipleProviders2305=== PAUSE TestValidateToken_MultipleProviders2306=== RUN TestValidateToken_NoMatchingProvider2307=== PAUSE TestValidateToken_NoMatchingProvider2308=== RUN TestValidateToken_KubernetesServiceAccount2309=== PAUSE TestValidateToken_KubernetesServiceAccount2310=== RUN TestNewValidator_KubernetesRequiresCA2311=== PAUSE TestNewValidator_KubernetesRequiresCA2312=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2313=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2314=== RUN TestScopes_LegacyProviderDefaultsToWrite2315=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2316=== RUN TestScopes_Rules2317=== PAUSE TestScopes_Rules2318=== RUN TestScopes_ConfigValidation2319=== PAUSE TestScopes_ConfigValidation2320=== CONT TestGlobMatch2321=== CONT TestValidateToken_NoMatchingProvider2322=== CONT TestValidateToken_Expired2323=== RUN TestGlobMatch/foo_foo2324=== PAUSE TestGlobMatch/foo_foo2325=== CONT TestValidateToken_WrongAudience2326=== CONT TestValidateToken_ValidToken2327=== CONT TestAudienceForIssuer2328=== CONT TestValidateToken_BoundSubjectMismatch2329=== CONT TestValidateToken_MultipleProviders2330=== CONT TestNewValidator_KubernetesRequiresCA2331=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2332=== CONT TestValidateToken_KubernetesServiceAccount2333=== CONT TestValidateToken_BoundClaimsMismatch2334=== CONT TestScopes_LegacyProviderDefaultsToWrite2335=== CONT TestScopes_ConfigValidation2336=== CONT TestScopes_Rules2337=== RUN TestGlobMatch/foo_bar2338=== PAUSE TestGlobMatch/foo_bar2339=== RUN TestGlobMatch/*_2340=== PAUSE TestGlobMatch/*_2341=== RUN TestGlobMatch/*_anything2342=== PAUSE TestGlobMatch/*_anything2343=== RUN TestGlobMatch/foo*_foo2344=== PAUSE TestGlobMatch/foo*_foo2345=== RUN TestGlobMatch/foo*_foobar2346=== PAUSE TestGlobMatch/foo*_foobar2347=== RUN TestGlobMatch/foo*_bar2348=== PAUSE TestGlobMatch/foo*_bar2349=== RUN TestGlobMatch/*bar_bar2350=== PAUSE TestGlobMatch/*bar_bar2351=== RUN TestGlobMatch/*bar_foobar2352=== PAUSE TestGlobMatch/*bar_foobar2353=== RUN TestGlobMatch/*bar_foo2354=== PAUSE TestGlobMatch/*bar_foo2355=== RUN TestGlobMatch/foo*bar_foobar2356=== PAUSE TestGlobMatch/foo*bar_foobar2357=== RUN TestGlobMatch/foo*bar_foo123bar2358=== PAUSE TestGlobMatch/foo*bar_foo123bar2359=== RUN TestGlobMatch/foo*bar_foobarbaz2360=== PAUSE TestGlobMatch/foo*bar_foobarbaz2361=== RUN TestGlobMatch/*/*_foo/bar2362=== PAUSE TestGlobMatch/*/*_foo/bar2363=== RUN TestGlobMatch/*/*_foo2364=== PAUSE TestGlobMatch/*/*_foo2365=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2366=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2367=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02368=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02369=== RUN TestGlobMatch/refs/*/main_refs/heads/main2370=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2371=== RUN TestGlobMatch/fo?_foo2372=== PAUSE TestGlobMatch/fo?_foo2373=== RUN TestGlobMatch/fo?_fo2374=== PAUSE TestGlobMatch/fo?_fo2375=== RUN TestGlobMatch/fo?_fooo2376=== PAUSE TestGlobMatch/fo?_fooo2377=== RUN TestGlobMatch/?oo_foo2378=== PAUSE TestGlobMatch/?oo_foo2379=== RUN TestGlobMatch/?oo_boo2380=== PAUSE TestGlobMatch/?oo_boo2381=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2382=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2383=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2384=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2385=== CONT TestGlobMatch/foo_foo2386--- PASS: TestAudienceForIssuer (0.00s)2387=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2388=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2389=== CONT TestGlobMatch/?oo_boo2390=== CONT TestGlobMatch/?oo_foo2391=== CONT TestGlobMatch/fo?_fooo2392=== CONT TestGlobMatch/fo?_fo2393=== CONT TestGlobMatch/fo?_foo2394=== CONT TestGlobMatch/refs/*/main_refs/heads/main2395=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02396=== CONT TestGlobMatch/*bar_bar2397=== CONT TestGlobMatch/foo*_bar2398=== CONT TestGlobMatch/foo*_foobar2399=== CONT TestGlobMatch/foo*_foo2400=== CONT TestGlobMatch/*_anything2401=== CONT TestGlobMatch/*_2402=== CONT TestGlobMatch/foo_bar2403=== CONT TestGlobMatch/*bar_foobar2404=== CONT TestGlobMatch/foo*bar_foobarbaz2405=== CONT TestGlobMatch/foo*bar_foo123bar2406=== CONT TestGlobMatch/*/*_foo/bar2407=== CONT TestGlobMatch/foo*bar_foobar2408=== CONT TestGlobMatch/*bar_foo2409=== CONT TestGlobMatch/*/*_foo2410=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2411--- PASS: TestScopes_ConfigValidation (0.00s)2412--- PASS: TestGlobMatch (0.00s)2413 --- PASS: TestGlobMatch/foo_foo (0.00s)2414 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2415 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2416 --- PASS: TestGlobMatch/?oo_boo (0.00s)2417 --- PASS: TestGlobMatch/?oo_foo (0.00s)2418 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2419 --- PASS: TestGlobMatch/fo?_fo (0.00s)2420 --- PASS: TestGlobMatch/fo?_foo (0.00s)2421 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2422 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2423 --- PASS: TestGlobMatch/*bar_bar (0.00s)2424 --- PASS: TestGlobMatch/foo*_bar (0.00s)2425 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2426 --- PASS: TestGlobMatch/foo*_foo (0.00s)2427 --- PASS: TestGlobMatch/*_anything (0.00s)2428 --- PASS: TestGlobMatch/*_ (0.00s)2429 --- PASS: TestGlobMatch/foo_bar (0.00s)2430 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2431 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2432 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2433 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2434 --- PASS: TestGlobMatch/*bar_foo (0.00s)2435 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2436 --- PASS: TestGlobMatch/*/*_foo (0.00s)2437 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)24382026/09/16 23:49:14 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC12324392026/09/16 23:49:14 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:42823/oidc24402026/09/16 23:49:14 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:34461/oidc24412026/09/16 23:49:14 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:33141/oidc24422026/09/16 23:49:14 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:34451/oidc24432026/09/16 23:49:14 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:38587/oidc24442026/09/16 23:49:14 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:40973/oidc24452026/09/16 23:49:14 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:38259/oidc24462026/09/16 23:49:14 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:42139/oidc24472026/09/16 23:49:14 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:37677/oidc24482026/09/16 23:49:14 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:39741/oidc2449--- PASS: TestValidateToken_BoundSubjectMismatch (0.02s)2450--- PASS: TestValidateToken_NoMatchingProvider (0.02s)2451--- PASS: TestValidateToken_WrongAudience (0.02s)24522026/09/16 23:49:14 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:373292453--- PASS: TestValidateToken_ValidToken (0.02s)2454--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.02s)2455--- PASS: TestValidateToken_BoundClaimsMismatch (0.02s)2456--- PASS: TestValidateToken_Expired (0.02s)2457--- PASS: TestValidateToken_MultipleProviders (0.02s)2458--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.02s)2459--- PASS: TestValidateToken_KubernetesServiceAccount (0.02s)2460--- PASS: TestScopes_Rules (0.02s)24612026/09/16 23:49:14 http: TLS handshake error from 127.0.0.1:38890: remote error: tls: bad certificate2462--- PASS: TestNewValidator_KubernetesRequiresCA (0.02s)2463PASS2464Running hook tests...2465=== RUN TestSendPathsEmpty2466=== PAUSE TestSendPathsEmpty2467=== RUN TestQueueEnqueueAndFetch2468=== PAUSE TestQueueEnqueueAndFetch2469=== RUN TestQueueDeduplication2470=== PAUSE TestQueueDeduplication2471=== RUN TestQueueRemove2472=== PAUSE TestQueueRemove2473=== RUN TestQueueFetchBatchLimit2474=== PAUSE TestQueueFetchBatchLimit2475=== RUN TestQueueRetryMovesToBack2476=== PAUSE TestQueueRetryMovesToBack2477=== RUN TestQueueFetchRemoveLifecycle2478=== PAUSE TestQueueFetchRemoveLifecycle2479=== RUN TestQueueConcurrentWriters2480=== PAUSE TestQueueConcurrentWriters2481=== RUN TestQueueRemoveLargeClosure2482=== PAUSE TestQueueRemoveLargeClosure2483=== RUN TestServerClientIntegration2484=== PAUSE TestServerClientIntegration2485=== RUN TestServerQueueError2486=== PAUSE TestServerQueueError2487=== RUN TestGetListenerSocketActivation2488 server_test.go:210: === RUN TestGetListenerSocketActivation2489 --- PASS: TestGetListenerSocketActivation (0.00s)2490 PASS2491 2492--- PASS: TestGetListenerSocketActivation (0.01s)2493=== RUN TestDrainIsolatesPoisonPath2494=== PAUSE TestDrainIsolatesPoisonPath2495=== RUN TestRunNotBlockedByPoisonHead2496=== PAUSE TestRunNotBlockedByPoisonHead2497=== RUN TestDrainGivesUpWhenServerDown2498=== PAUSE TestDrainGivesUpWhenServerDown2499=== RUN TestFailedPathPrunedByLaterClosure2500=== PAUSE TestFailedPathPrunedByLaterClosure2501=== RUN TestWorkerUploadsAndRemoves2502=== PAUSE TestWorkerUploadsAndRemoves2503=== RUN TestWorkerSkipsGCdPaths2504=== PAUSE TestWorkerSkipsGCdPaths2505=== RUN TestWorkerPrunesClosureDeps2506=== PAUSE TestWorkerPrunesClosureDeps2507=== RUN TestDrainTimeout2508=== PAUSE TestDrainTimeout2509=== CONT TestSendPathsEmpty2510=== CONT TestServerQueueError2511=== CONT TestWorkerUploadsAndRemoves2512--- PASS: TestSendPathsEmpty (0.00s)2513=== CONT TestQueueFetchBatchLimit2514=== CONT TestQueueRemove2515=== CONT TestQueueDeduplication2516=== CONT TestQueueEnqueueAndFetch2517=== CONT TestDrainGivesUpWhenServerDown2518=== CONT TestFailedPathPrunedByLaterClosure2519=== CONT TestQueueRemoveLargeClosure2520=== CONT TestServerClientIntegration2521=== CONT TestRunNotBlockedByPoisonHead2522=== CONT TestDrainIsolatesPoisonPath25232026/09/16 23:49:14 ERROR Failed to queue paths error="permission denied" count=12524=== CONT TestQueueConcurrentWriters2525=== CONT TestQueueFetchRemoveLifecycle2526=== CONT TestWorkerPrunesClosureDeps2527=== CONT TestDrainTimeout2528=== CONT TestWorkerSkipsGCdPaths2529=== CONT TestQueueRetryMovesToBack2530--- PASS: TestServerQueueError (0.01s)2531--- PASS: TestServerClientIntegration (0.00s)25322026/09/16 23:49:14 INFO Upload queue status pending=325332026/09/16 23:49:14 INFO Uploading batch count=225342026/09/16 23:49:14 INFO Uploading batch count=12535--- PASS: TestQueueEnqueueAndFetch (0.02s)25362026/09/16 23:49:14 ERROR Upload failed error="upload failed" count=125372026/09/16 23:49:14 INFO Uploading batch count=225382026/09/16 23:49:14 INFO Uploading batch count=125392026/09/16 23:49:14 ERROR Upload failed error="upload failed" count=125402026/09/16 23:49:14 ERROR Upload failed error="upload failed" count=225412026/09/16 23:49:14 INFO Uploading batch count=425422026/09/16 23:49:14 ERROR Upload failed error="upload failed" count=425432026/09/16 23:49:14 INFO Upload queue status pending=225442026/09/16 23:49:14 INFO Upload queue status pending=225452026/09/16 23:49:14 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1677357745/002/a25462026/09/16 23:49:14 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerSkipsGCdPaths1838243656/002/nonexistent2547--- PASS: TestQueueFetchBatchLimit (0.02s)25482026/09/16 23:49:14 INFO Upload queue status pending=225492026/09/16 23:49:14 INFO Uploading batch count=225502026/09/16 23:49:14 INFO Uploading batch count=12551--- PASS: TestQueueDeduplication (0.02s)25522026/09/16 23:49:14 INFO Uploading batch count=125532026/09/16 23:49:14 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainIsolatesPoisonPath4242717375/002/bbb2554--- PASS: TestQueueRetryMovesToBack (0.02s)2555--- PASS: TestQueueFetchRemoveLifecycle (0.02s)25562026/09/16 23:49:14 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1677357745/002/b25572026/09/16 23:49:14 INFO Uploading batch count=12558--- PASS: TestQueueRemove (0.02s)25592026/09/16 23:49:14 INFO Uploading batch count=125602026/09/16 23:49:14 INFO Uploading batch count=225612026/09/16 23:49:14 ERROR Upload failed error="upload failed" count=225622026/09/16 23:49:14 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1677357745/002/c25632026/09/16 23:49:14 INFO Uploading batch count=125642026/09/16 23:49:14 ERROR Upload failed error="upload failed" count=125652026/09/16 23:49:14 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1677357745/002/d25662026/09/16 23:49:14 INFO Uploading batch count=125672026/09/16 23:49:14 ERROR Upload failed error="upload failed" count=12568--- PASS: TestFailedPathPrunedByLaterClosure (0.02s)25692026/09/16 23:49:14 INFO Uploading batch count=225702026/09/16 23:49:14 ERROR Upload failed error="upload failed" count=225712026/09/16 23:49:14 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1677357745/002/e25722026/09/16 23:49:14 INFO Uploading batch count=125732026/09/16 23:49:14 ERROR Upload failed error="upload failed" count=125742026/09/16 23:49:14 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1677357745/002/f25752026/09/16 23:49:14 ERROR Drain finished with paths left in queue remaining=125762026/09/16 23:49:14 ERROR Drain finished with paths left in queue remaining=102577--- PASS: TestDrainIsolatesPoisonPath (0.03s)2578--- PASS: TestDrainGivesUpWhenServerDown (0.03s)2579--- PASS: TestWorkerSkipsGCdPaths (0.04s)2580--- PASS: TestWorkerPrunesClosureDeps (0.04s)2581--- PASS: TestWorkerUploadsAndRemoves (0.04s)2582--- PASS: TestQueueRemoveLargeClosure (0.10s)25832026/09/16 23:49:14 ERROR Upload failed error="context deadline exceeded" count=225842026/09/16 23:49:14 ERROR Drain finished with paths left in queue remaining=42585--- PASS: TestDrainTimeout (0.22s)2586--- PASS: TestQueueConcurrentWriters (0.28s)25872026/09/16 23:49:15 INFO Uploading batch count=125882026/09/16 23:49:15 INFO Uploading batch count=125892026/09/16 23:49:15 INFO Uploading batch count=125902026/09/16 23:49:15 ERROR Upload failed error="upload failed" count=125912026/09/16 23:49:15 INFO Uploading batch count=125922026/09/16 23:49:15 ERROR Upload failed error="upload failed" count=125932026/09/16 23:49:15 INFO Uploading batch count=125942026/09/16 23:49:15 ERROR Upload failed error="upload failed" count=125952026/09/16 23:49:15 INFO Uploading batch count=125962026/09/16 23:49:15 ERROR Upload failed error="upload failed" count=125972026/09/16 23:49:15 ERROR Drain finished with paths left in queue remaining=12598--- PASS: TestRunNotBlockedByPoisonHead (1.04s)2599PASS