niks3-go-unit-tests
checks.x86_64-linux.go-unit-tests
· build #215
· 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.04s)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 TestParsePathInfoJSON92=== CONT TestScriptTokenEmptyCommand93=== RUN TestParsePathInfoJSON/Nix_format94=== PAUSE TestParsePathInfoJSON/Nix_format95=== RUN TestParsePathInfoJSON/Lix_format96=== PAUSE TestParsePathInfoJSON/Lix_format97=== RUN TestParsePathInfoJSON/empty_input98=== PAUSE TestParsePathInfoJSON/empty_input99=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess100=== CONT TestScriptTokenBadJSON101=== CONT TestScriptTokenEmptyToken102=== CONT TestScriptTokenCachesUntilRefresh1032026/09/18 13:10:00 WARN Rate limiter enabled after throttle name=server-test rate=5104=== CONT TestScriptTokenNoExpiryRerunsEveryCall105=== CONT TestFileTokenEmpty106=== CONT TestFileTokenMissing107=== CONT TestFileTokenReadsAndCaches108=== CONT TestStreamPushGivesUpOnDeadServer109=== CONT TestSetClientTLSErrors110=== CONT TestSetClientTLS1112026/09/18 13:10:00 ERROR Upload failed error="connection refused" count=201122026/09/18 13:10:00 ERROR Server seems unavailable, giving up on batch untried=17113=== CONT TestStreamPushBatchesUnderLoad114=== CONT TestStreamPushRequestLine115=== CONT TestDumpPathMatchesNix116=== CONT TestStreamPushIsolatesFailures117=== CONT TestConvertHashToNix32118=== CONT TestDoWithRetry_BodyReplayedViaGetBody119=== CONT TestStreamPushReportsEveryPath120=== CONT TestResolveStorePath121=== CONT TestParsePathInfoJSONMultiplePaths122=== CONT TestSetClientTLSDoesNotMutateDefaultTransport123--- PASS: TestStaticToken (0.00s)124=== CONT TestPathInfoHashCompatibility125=== CONT TestScriptTokenScriptFails126=== RUN TestParsePathInfoJSON/whitespace_only127=== CONT TestGetStorePathHash128=== CONT TestRateLimiterFeedback129=== CONT TestDumpPathWriterError130--- PASS: TestScriptTokenEmptyCommand (0.00s)131--- PASS: TestFileTokenMissing (0.00s)132--- PASS: TestFileTokenEmpty (0.00s)133--- PASS: TestScriptTokenBadJSON (0.00s)134=== RUN TestConvertHashToNix32/SRI_format_to_Nix32135=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)136=== CONT TestPathInfoCACompatibility137=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths138=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)139=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon140=== RUN TestRateLimiterFeedback/429_enables_limiter141=== PAUSE TestRateLimiterFeedback/429_enables_limiter142=== CONT TestEncodeNixBase32WithRealHash1432026/09/18 13:10:00 ERROR Upload failed error="stale build claim" count=1144=== CONT TestDumpPathSingleFile145=== PAUSE TestParsePathInfoJSON/whitespace_only146--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)1472026/09/18 13:10:00 ERROR Upload failed error="bad path" count=3148--- PASS: TestDoServerRequestAttachesToken (0.01s)149=== RUN TestGetStorePathHash/valid_store_path150=== CONT TestShellSplitErrors151=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32152=== RUN TestPathInfoCACompatibility/null_ca_field153=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths154=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon155=== RUN TestRateLimiterFeedback/503_enables_limiter156=== CONT TestPartSizeForNAR157=== RUN TestPartSizeForNAR/zero_stays_at_minimum158=== RUN TestParsePathInfoJSON/invalid_JSON159--- PASS: TestFileTokenReadsAndCaches (0.00s)160--- PASS: TestScriptTokenEmptyToken (0.01s)161=== CONT TestEncodeNixBase32162=== RUN TestSetClientTLSErrors/missing_cert_file163=== PAUSE TestRateLimiterFeedback/503_enables_limiter164=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI165=== PAUSE TestGetStorePathHash/valid_store_path166=== CONT TestUploadMultipart_SupersededByPeer167=== CONT TestFilterOversizedClosures168=== RUN TestConvertHashToNix32/already_Nix32_format169=== PAUSE TestPathInfoCACompatibility/null_ca_field170=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum171=== PAUSE TestParsePathInfoJSON/invalid_JSON172=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths173=== CONT TestCaseHackSuffix174--- PASS: TestStreamPushReportsEveryPath (0.00s)175=== RUN TestEncodeNixBase32/test_string_hash176=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter177=== RUN TestPathInfoCACompatibility/old_string_format_-_text178=== RUN TestGetStorePathHash/basename_without_hyphen_should_error179=== RUN TestFilterOversizedClosures/no_limit_keeps_everything180=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter181=== RUN TestSetClientTLS/rejects_connection_without_client_cert1822026/09/18 13:10:00 WARN Rate limiter enabled after throttle name=server-test rate=5183=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error184=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything1852026/09/18 13:10:00 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:36241186=== RUN TestUploadMultipart_SupersededByPeer/exists187=== RUN TestPartSizeForNAR/small_stays_at_minimum188=== PAUSE TestPartSizeForNAR/small_stays_at_minimum189=== PAUSE TestUploadMultipart_SupersededByPeer/exists190=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error191=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped192=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped193=== RUN TestFilterOversizedClosures/all_closures_skipped194=== PAUSE TestFilterOversizedClosures/all_closures_skipped195=== RUN TestUploadMultipart_SupersededByPeer/missing196=== CONT TestParsePathInfoJSON/invalid_JSON197=== CONT TestParsePathInfoJSON/Lix_format198=== PAUSE TestUploadMultipart_SupersededByPeer/missing199=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths2002026/09/18 13:10:00 WARN Rate limiter backed off name=server-test rate=52012026/09/18 13:10:00 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:36241202--- PASS: TestResolveStorePath (0.00s)203--- PASS: TestEncodeNixBase32WithRealHash (0.00s)204--- PASS: TestShellSplitErrors (0.00s)205=== PAUSE TestSetClientTLSErrors/missing_cert_file206=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text207=== PAUSE TestEncodeNixBase32/test_string_hash208=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert209=== RUN TestSetClientTLSErrors/missing_key_file210=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI211=== RUN TestEncodeNixBase32/empty_input212=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter213=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum214=== PAUSE TestConvertHashToNix32/already_Nix32_format215=== CONT TestParsePathInfoJSON/Nix_format216=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error217=== CONT TestParsePathInfoJSON/empty_input218=== CONT TestParsePathInfoJSON/whitespace_only219=== CONT TestFilterOversizedClosures/no_limit_keeps_everything220=== CONT TestFilterOversizedClosures/all_closures_skipped2212026/09/18 13:10:00 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=50222=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped2232026/09/18 13:10:00 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--- PASS: TestStreamPushIsolatesFailures (0.00s)225--- PASS: TestScriptTokenScriptFails (0.00s)226=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA227=== PAUSE TestSetClientTLSErrors/missing_key_file228=== RUN TestSetClientTLSErrors/missing_ca_file229=== PAUSE TestSetClientTLSErrors/missing_ca_file230=== RUN TestSetClientTLSErrors/invalid_ca_file231=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive232=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512233=== PAUSE TestEncodeNixBase32/empty_input234=== CONT TestUploadMultipart_SupersededByPeer/exists235=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum236=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter237=== CONT TestUploadMultipart_SupersededByPeer/missing238=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts239=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts240=== RUN TestPartSizeForNAR/1_TiB241=== PAUSE TestPartSizeForNAR/1_TiB242=== RUN TestPartSizeForNAR/5_TiB_S3_max_object243=== RUN TestConvertHashToNix32/invalid_format244=== PAUSE TestConvertHashToNix32/invalid_format245=== CONT TestConvertHashToNix32/SRI_format_to_Nix32246=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths247=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error248=== CONT TestConvertHashToNix32/invalid_format249=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths250--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.00s)251--- PASS: TestScriptTokenCachesUntilRefresh (0.01s)252=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA253=== PAUSE TestSetClientTLSErrors/invalid_ca_file254=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive255=== CONT TestSetClientTLSErrors/missing_cert_file256=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512257=== CONT TestEncodeNixBase32/test_string_hash258=== CONT TestSetClientTLSErrors/invalid_ca_file259=== CONT TestEncodeNixBase32/empty_input260=== CONT TestRateLimiterFeedback/429_enables_limiter261=== CONT TestRateLimiterFeedback/503_enables_limiter262=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)263=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter264=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter265=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object266=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error267--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.01s)268=== RUN TestSetClientTLS/preserves_debug_logging_transport269=== PAUSE TestSetClientTLS/preserves_debug_logging_transport270=== RUN TestPartSizeForNAR/capped_at_5_GiB271=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon272=== RUN TestPathInfoCACompatibility/new_structured_format_-_text273--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.01s)274=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text275=== CONT TestSetClientTLS/preserves_debug_logging_transport276=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method277=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method278=== CONT TestConvertHashToNix32/already_Nix32_format279=== CONT TestGetStorePathHash/valid_store_path280--- PASS: TestParsePathInfoJSON (0.01s)281 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)282 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)283 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)284 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)285 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)286=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha5122872026/09/18 13:10:00 WARN Rate limiter enabled after throttle name=server-test rate=5288--- PASS: TestEncodeNixBase32 (0.01s)289 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)290 --- PASS: TestEncodeNixBase32/empty_input (0.00s)2912026/09/18 13:10:00 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:32983292=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI293=== CONT TestPathInfoCACompatibility/null_ca_field2942026/09/18 13:10:00 WARN Rate limiter enabled after throttle name=server-test rate=5295=== CONT TestPathInfoCACompatibility/new_structured_format_-_text2962026/09/18 13:10:00 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:33447297--- PASS: TestParsePathInfoJSONMultiplePaths (0.01s)298 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)299 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)300=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method3012026/09/18 13:10:00 WARN Rate limiter backed off name=server-test rate=5302=== CONT TestSetClientTLS/rejects_connection_without_client_cert3032026/09/18 13:10:00 WARN Rate limiter backed off name=server-test rate=5304=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA305=== CONT TestSetClientTLSErrors/missing_ca_file306=== CONT TestSetClientTLSErrors/missing_key_file307=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error308=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error309=== CONT TestGetStorePathHash/basename_without_hyphen_should_error310=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive311=== PAUSE TestPartSizeForNAR/capped_at_5_GiB312=== CONT TestPartSizeForNAR/zero_stays_at_minimum313=== CONT TestPathInfoCACompatibility/old_string_format_-_text314=== CONT TestPartSizeForNAR/1_TiB315--- PASS: TestFilterOversizedClosures (0.00s)316 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)317 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)318 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)319=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts320=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum321=== CONT TestPartSizeForNAR/small_stays_at_minimum322=== CONT TestPartSizeForNAR/capped_at_5_GiB323=== CONT TestPartSizeForNAR/5_TiB_S3_max_object324--- PASS: TestConvertHashToNix32 (0.01s)325 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)326 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)327 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)328--- PASS: TestPathInfoHashCompatibility (0.01s)329 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)330 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)331 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)332 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)333--- PASS: TestUploadMultipart_SupersededByPeer (0.00s)334 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)335 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)336--- PASS: TestRateLimiterFeedback (0.01s)337 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)338 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)339 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)340 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)341--- PASS: TestPathInfoCACompatibility (0.01s)342 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)343 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)344 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)345 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)346 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)347--- PASS: TestPartSizeForNAR (0.01s)348 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)349 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)350 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)351 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)352 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)353 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)354 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)355--- PASS: TestGetStorePathHash (0.01s)356 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)357 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)358 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)359 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)360--- PASS: TestSetClientTLSErrors (0.02s)361 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)362 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)363 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)364 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)3652026/09/18 13:10:00 http: TLS handshake error from 127.0.0.1:34536: remote error: tls: bad certificate366--- PASS: TestSetClientTLS (0.02s)367 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.00s)368 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.00s)369 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.01s)370--- PASS: TestStreamPushRequestLine (0.03s)371--- PASS: TestDumpPathWriterError (0.04s)372--- PASS: TestCaseHackSuffix (0.03s)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/postgres144647323/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/postgres144647323/data -l logfile start405406/build/postgres144647323:5432 - no response4072026-09-18 13:10:02.347 UTC [129] LOG: starting PostgreSQL 18.6 on x86_64-pc-linux-gnu, compiled by clang version 21.1.8, 64-bit4082026-09-18 13:10:02.347 UTC [129] LOG: listening on Unix socket "/build/postgres144647323/.s.PGSQL.5432"4092026-09-18 13:10:02.352 UTC [136] LOG: database system was shut down at 2026-09-18 13:10:02 UTC4102026-09-18 13:10:02.356 UTC [129] LOG: database system is ready to accept connections411/build/postgres144647323: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-18 13:10:02.844 UTC [566] ERROR: relation "goose_db_version" does not exist at character 364682026-09-18 13:10:02.844 UTC [566] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC4692026/09/18 13:10:02 OK 20241026095416_initial_model.sql (8.48ms)4702026/09/18 13:10:02 OK 20251210153512_drop_unused_gin_index.sql (1.75ms)4712026/09/18 13:10:02 OK 20251218171726_add_pins.sql (2.25ms)4722026/09/18 13:10:02 OK 20260628120000_add_object_size_and_stats.sql (2.18ms)4732026/09/18 13:10:02 OK 20260905000000_add_claims.sql (2.48ms)4742026/09/18 13:10:02 goose: successfully migrated database to version: 202609050000004752026/09/18 13:10:02 OK 1_commit_pending_closure.sql (1.69ms)4762026/09/18 13:10:02 OK 2_object_stats_trigger.sql (731.3µs)4772026/09/18 13:10:02 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/18 13:10:02 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5792026/09/18 13:10:02 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5802026/09/18 13:10:02 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5812026/09/18 13:10:03 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5822026/09/18 13:10:03 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5832026/09/18 13:10:03 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5842026/09/18 13:10:03 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5852026/09/18 13:10:03 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5862026/09/18 13:10:03 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5872026/09/18 13:10:03 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 TestCreatePendingClosureRejectsOversizedNAR611=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT612=== CONT TestCompleteMultipartUnregistered6132026/09/18 13:10:03 INFO Received uploads request method=POST path=/api/pending_closures614=== CONT TestService_verifyS3Integrity615=== CONT TestService_createPendingClosureHandler616=== CONT TestService_cleanupPendingClosuresHandler617=== CONT TestUploadHandlersRejectOversizedBody618=== CONT TestUploadHandlersRejectInvalidKeys619=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info620=== CONT TestIsValidUploadKey621=== CONT TestProxyWriteTimeout622=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle623=== CONT TestSkippedUploadsHandler624=== CONT TestParseSize625=== CONT TestService_Rustfstest626=== CONT TestPresignedUploadRegisteredBeforeCommit627=== CONT TestCompletedNarNotReofferedAcrossClosures628=== CONT TestCompleteMultipartUpload_ErrorButObjectExists629=== CONT TestRedundantMultipartUpload630=== CONT TestReadRedirectUsesPublicS3URL631=== CONT TestReadProxyRangeRequest632=== CONT TestReadRedirectKeepsNarinfoProxied633=== CONT TestReadRedirectNar634=== CONT TestReadProxyDisabled635--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)636=== CONT TestReadProxyRootRedirectsToIndexHTML637=== RUN TestProxyWriteTimeout/narinfo638=== PAUSE TestProxyWriteTimeout/narinfo639=== RUN TestProxyWriteTimeout/1_GiB_nar640=== PAUSE TestProxyWriteTimeout/1_GiB_nar641=== RUN TestProxyWriteTimeout/10_GiB_nar642=== PAUSE TestProxyWriteTimeout/10_GiB_nar643=== RUN TestProxyWriteTimeout/unknown_size644=== PAUSE TestProxyWriteTimeout/unknown_size645--- PASS: TestParseSize (0.00s)6462026/09/18 13:10:03 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000647=== RUN TestIsValidUploadKey/narinfo648=== CONT TestReadProxyConditionalGet649=== CONT TestReadProxyHead650--- PASS: TestSkippedUploadsHandler (0.01s)651=== PAUSE TestIsValidUploadKey/narinfo652=== RUN TestIsValidUploadKey/nar_zst653=== PAUSE TestIsValidUploadKey/nar_zst654=== RUN TestIsValidUploadKey/nar_xz655=== PAUSE TestIsValidUploadKey/nar_xz656=== RUN TestIsValidUploadKey/nar_plain657=== PAUSE TestIsValidUploadKey/nar_plain658=== RUN TestIsValidUploadKey/listing659=== PAUSE TestIsValidUploadKey/listing660=== RUN TestIsValidUploadKey/build_log661=== PAUSE TestIsValidUploadKey/build_log662=== RUN TestIsValidUploadKey/build_log_home-manager_file663=== PAUSE TestIsValidUploadKey/build_log_home-manager_file664=== RUN TestIsValidUploadKey/build_log_plus_in_name665=== PAUSE TestIsValidUploadKey/build_log_plus_in_name666=== RUN TestIsValidUploadKey/build_log_question_mark667=== PAUSE TestIsValidUploadKey/build_log_question_mark668=== RUN TestIsValidUploadKey/build_log_equals669=== PAUSE TestIsValidUploadKey/build_log_equals670=== RUN TestIsValidUploadKey/realisation671=== PAUSE TestIsValidUploadKey/realisation672=== RUN TestIsValidUploadKey/realisation_plus_in_output673=== PAUSE TestIsValidUploadKey/realisation_plus_in_output674=== RUN TestIsValidUploadKey/nix-cache-info675=== PAUSE TestIsValidUploadKey/nix-cache-info676=== RUN TestIsValidUploadKey/index.html677=== PAUSE TestIsValidUploadKey/index.html678=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info679=== CONT TestReadProxyInvalidPath680=== RUN TestIsValidUploadKey/narinfo_key,_nar_type681=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type682=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal683=== RUN TestIsValidUploadKey/nar_key,_narinfo_type684=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal685=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key686=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key687=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key688=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key689=== CONT TestReadProxy404690=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type691=== RUN TestIsValidUploadKey/listing_key,_narinfo_type692=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type693=== RUN TestIsValidUploadKey/traversal694=== PAUSE TestIsValidUploadKey/traversal695=== RUN TestIsValidUploadKey/traversal_nar696=== PAUSE TestIsValidUploadKey/traversal_nar697=== RUN TestIsValidUploadKey/absolute698=== PAUSE TestIsValidUploadKey/absolute699=== RUN TestIsValidUploadKey/empty_key700=== PAUSE TestIsValidUploadKey/empty_key701=== RUN TestIsValidUploadKey/unknown_type702=== PAUSE TestIsValidUploadKey/unknown_type703=== CONT TestReadProxyNarStreaming704=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure705=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure706=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart707=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart708=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts709=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts710=== CONT TestReadProxyNarinfoAlreadyDecompressed7112026-09-18 13:10:03.435 UTC [639] ERROR: relation "goose_db_version" does not exist at character 367122026-09-18 13:10:03.435 UTC [639] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7132026-09-18 13:10:03.462 UTC [640] ERROR: relation "goose_db_version" does not exist at character 367142026-09-18 13:10:03.462 UTC [640] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7152026-09-18 13:10:03.467 UTC [641] ERROR: relation "goose_db_version" does not exist at character 367162026-09-18 13:10:03.467 UTC [641] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7172026-09-18 13:10:03.481 UTC [642] ERROR: relation "goose_db_version" does not exist at character 367182026-09-18 13:10:03.481 UTC [642] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7192026/09/18 13:10:03 OK 20241026095416_initial_model.sql (18.91ms)7202026-09-18 13:10:03.485 UTC [643] ERROR: relation "goose_db_version" does not exist at character 367212026-09-18 13:10:03.485 UTC [643] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7222026-09-18 13:10:03.490 UTC [644] ERROR: relation "goose_db_version" does not exist at character 367232026-09-18 13:10:03.490 UTC [644] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7242026-09-18 13:10:03.494 UTC [645] ERROR: relation "goose_db_version" does not exist at character 367252026-09-18 13:10:03.494 UTC [645] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7262026-09-18 13:10:03.494 UTC [646] ERROR: relation "goose_db_version" does not exist at character 367272026-09-18 13:10:03.494 UTC [646] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7282026/09/18 13:10:03 OK 20251210153512_drop_unused_gin_index.sql (12.41ms)7292026/09/18 13:10:03 OK 20241026095416_initial_model.sql (23.77ms)7302026/09/18 13:10:03 OK 20251210153512_drop_unused_gin_index.sql (2.37ms)7312026/09/18 13:10:03 OK 20251218171726_add_pins.sql (14.18ms)7322026/09/18 13:10:03 OK 20251218171726_add_pins.sql (11.26ms)7332026/09/18 13:10:03 OK 20241026095416_initial_model.sql (33.47ms)7342026/09/18 13:10:03 OK 20251210153512_drop_unused_gin_index.sql (4.65ms)7352026/09/18 13:10:03 OK 20260628120000_add_object_size_and_stats.sql (8.42ms)7362026/09/18 13:10:03 OK 20260628120000_add_object_size_and_stats.sql (8.26ms)7372026/09/18 13:10:03 OK 20241026095416_initial_model.sql (30.53ms)7382026/09/18 13:10:03 OK 20260905000000_add_claims.sql (18.38ms)7392026/09/18 13:10:03 goose: successfully migrated database to version: 202609050000007402026/09/18 13:10:03 OK 20260905000000_add_claims.sql (20.46ms)7412026/09/18 13:10:03 goose: successfully migrated database to version: 202609050000007422026/09/18 13:10:03 OK 20251218171726_add_pins.sql (24.16ms)7432026/09/18 13:10:03 OK 20241026095416_initial_model.sql (40.89ms)7442026/09/18 13:10:03 OK 20251210153512_drop_unused_gin_index.sql (13.78ms)7452026/09/18 13:10:03 OK 1_commit_pending_closure.sql (5.29ms)7462026/09/18 13:10:03 OK 1_commit_pending_closure.sql (4.24ms)7472026/09/18 13:10:03 OK 20251210153512_drop_unused_gin_index.sql (4.36ms)7482026/09/18 13:10:03 OK 2_object_stats_trigger.sql (2.73ms)7492026/09/18 13:10:03 goose: up to current file version: 27502026/09/18 13:10:03 OK 2_object_stats_trigger.sql (2.54ms)7512026/09/18 13:10:03 goose: up to current file version: 27522026/09/18 13:10:03 OK 20241026095416_initial_model.sql (37.83ms)7532026/09/18 13:10:03 OK 20251218171726_add_pins.sql (7.14ms)7542026/09/18 13:10:03 OK 20260628120000_add_object_size_and_stats.sql (11.01ms)7552026/09/18 13:10:03 OK 20251218171726_add_pins.sql (8.59ms)7562026/09/18 13:10:03 OK 20241026095416_initial_model.sql (44.28ms)7572026/09/18 13:10:03 OK 20241026095416_initial_model.sql (44.13ms)7582026/09/18 13:10:03 OK 20251210153512_drop_unused_gin_index.sql (5.88ms)7592026/09/18 13:10:03 OK 20260628120000_add_object_size_and_stats.sql (7.15ms)7602026/09/18 13:10:03 OK 20251210153512_drop_unused_gin_index.sql (3.57ms)7612026/09/18 13:10:03 OK 20260905000000_add_claims.sql (7.43ms)7622026/09/18 13:10:03 goose: successfully migrated database to version: 202609050000007632026/09/18 13:10:03 OK 20251210153512_drop_unused_gin_index.sql (5.4ms)7642026-09-18 13:10:03.564 UTC [651] ERROR: relation "goose_db_version" does not exist at character 367652026-09-18 13:10:03.564 UTC [651] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7662026-09-18 13:10:03.565 UTC [653] ERROR: relation "goose_db_version" does not exist at character 367672026-09-18 13:10:03.565 UTC [653] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7682026-09-18 13:10:03.565 UTC [652] ERROR: relation "goose_db_version" does not exist at character 367692026-09-18 13:10:03.565 UTC [652] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7702026/09/18 13:10:03 OK 20260905000000_add_claims.sql (5.63ms)7712026/09/18 13:10:03 goose: successfully migrated database to version: 202609050000007722026/09/18 13:10:03 OK 20251218171726_add_pins.sql (7.93ms)7732026/09/18 13:10:03 OK 20260628120000_add_object_size_and_stats.sql (8.68ms)7742026/09/18 13:10:03 OK 20251218171726_add_pins.sql (6.14ms)7752026/09/18 13:10:03 OK 1_commit_pending_closure.sql (4.64ms)7762026/09/18 13:10:03 OK 1_commit_pending_closure.sql (4.46ms)7772026/09/18 13:10:03 OK 2_object_stats_trigger.sql (2.67ms)7782026/09/18 13:10:03 goose: up to current file version: 27792026/09/18 13:10:03 OK 20251218171726_add_pins.sql (7.19ms)7802026/09/18 13:10:03 OK 20260905000000_add_claims.sql (4.35ms)7812026/09/18 13:10:03 goose: successfully migrated database to version: 202609050000007822026/09/18 13:10:03 OK 2_object_stats_trigger.sql (2.37ms)7832026/09/18 13:10:03 goose: up to current file version: 27842026-09-18 13:10:03.575 UTC [654] ERROR: relation "goose_db_version" does not exist at character 367852026-09-18 13:10:03.575 UTC [654] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7862026/09/18 13:10:03 INFO Received uploads request method=POST path=/api/pending_closures7872026/09/18 13:10:03 OK 20260628120000_add_object_size_and_stats.sql (7.98ms)7882026/09/18 13:10:03 OK 1_commit_pending_closure.sql (6.29ms)7892026/09/18 13:10:03 OK 20260628120000_add_object_size_and_stats.sql (11.2ms)7902026-09-18 13:10:03.582 UTC [655] ERROR: relation "goose_db_version" does not exist at character 367912026-09-18 13:10:03.582 UTC [655] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7922026-09-18 13:10:03.589 UTC [657] ERROR: relation "goose_db_version" does not exist at character 367932026-09-18 13:10:03.589 UTC [657] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7942026/09/18 13:10:03 OK 20260628120000_add_object_size_and_stats.sql (18.03ms)7952026/09/18 13:10:03 OK 2_object_stats_trigger.sql (15.18ms)7962026/09/18 13:10:03 goose: up to current file version: 27972026/09/18 13:10:03 OK 20241026095416_initial_model.sql (14.15ms)7982026/09/18 13:10:03 OK 20260905000000_add_claims.sql (16.85ms)7992026/09/18 13:10:03 goose: successfully migrated database to version: 202609050000008002026/09/18 13:10:03 OK 20260905000000_add_claims.sql (15.37ms)8012026/09/18 13:10:03 goose: successfully migrated database to version: 202609050000008022026/09/18 13:10:03 OK 20260905000000_add_claims.sql (4.7ms)8032026/09/18 13:10:03 goose: successfully migrated database to version: 202609050000008042026/09/18 13:10:03 OK 20241026095416_initial_model.sql (15.15ms)8052026/09/18 13:10:03 INFO Received uploads request method=POST path=/api/pending_closures8062026/09/18 13:10:03 OK 20251210153512_drop_unused_gin_index.sql (1.6ms)8072026/09/18 13:10:03 OK 1_commit_pending_closure.sql (2.81ms)8082026/09/18 13:10:03 OK 20251210153512_drop_unused_gin_index.sql (3.25ms)8092026/09/18 13:10:03 OK 2_object_stats_trigger.sql (1.5ms)8102026/09/18 13:10:03 goose: up to current file version: 28112026/09/18 13:10:03 OK 1_commit_pending_closure.sql (4.34ms)8122026/09/18 13:10:03 OK 1_commit_pending_closure.sql (3.88ms)8132026/09/18 13:10:03 OK 20251218171726_add_pins.sql (3.84ms)8142026/09/18 13:10:03 OK 20241026095416_initial_model.sql (10.36ms)8152026/09/18 13:10:03 OK 2_object_stats_trigger.sql (2.69ms)8162026/09/18 13:10:03 goose: up to current file version: 28172026/09/18 13:10:03 OK 2_object_stats_trigger.sql (2.81ms)8182026/09/18 13:10:03 goose: up to current file version: 28192026-09-18 13:10:03.604 UTC [659] ERROR: relation "goose_db_version" does not exist at character 368202026-09-18 13:10:03.604 UTC [659] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8212026-09-18 13:10:03.605 UTC [660] ERROR: relation "goose_db_version" does not exist at character 368222026-09-18 13:10:03.605 UTC [660] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8232026/09/18 13:10:03 OK 20260628120000_add_object_size_and_stats.sql (5.2ms)8242026-09-18 13:10:03.605 UTC [658] ERROR: relation "goose_db_version" does not exist at character 368252026-09-18 13:10:03.605 UTC [658] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8262026/09/18 13:10:03 OK 20241026095416_initial_model.sql (10.68ms)8272026/09/18 13:10:03 OK 20251218171726_add_pins.sql (6.62ms)8282026/09/18 13:10:03 OK 20251210153512_drop_unused_gin_index.sql (3.81ms)8292026/09/18 13:10:03 OK 20241026095416_initial_model.sql (10.76ms)8302026/09/18 13:10:03 OK 20241026095416_initial_model.sql (9.66ms)8312026-09-18 13:10:03.606 UTC [661] ERROR: relation "goose_db_version" does not exist at character 368322026-09-18 13:10:03.606 UTC [661] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8332026-09-18 13:10:03.606 UTC [662] ERROR: relation "goose_db_version" does not exist at character 368342026-09-18 13:10:03.606 UTC [662] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8352026/09/18 13:10:03 OK 20251210153512_drop_unused_gin_index.sql (1.21ms)8362026-09-18 13:10:03.607 UTC [663] ERROR: relation "goose_db_version" does not exist at character 368372026-09-18 13:10:03.607 UTC [663] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8382026/09/18 13:10:03 OK 20251210153512_drop_unused_gin_index.sql (1.46ms)8392026/09/18 13:10:03 OK 20251210153512_drop_unused_gin_index.sql (1.51ms)8402026/09/18 13:10:03 INFO Received uploads request method=POST path=/api/pending_closures8412026-09-18 13:10:03.607 UTC [664] ERROR: relation "goose_db_version" does not exist at character 368422026-09-18 13:10:03.607 UTC [664] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8432026/09/18 13:10:03 OK 20260905000000_add_claims.sql (2.91ms)8442026/09/18 13:10:03 goose: successfully migrated database to version: 202609050000008452026/09/18 13:10:03 OK 20251218171726_add_pins.sql (4.08ms)8462026/09/18 13:10:03 OK 20251218171726_add_pins.sql (3.26ms)8472026/09/18 13:10:03 OK 20260628120000_add_object_size_and_stats.sql (4.76ms)8482026/09/18 13:10:03 OK 20251218171726_add_pins.sql (3.04ms)8492026/09/18 13:10:03 OK 1_commit_pending_closure.sql (2.32ms)8502026/09/18 13:10:03 OK 20251218171726_add_pins.sql (4.11ms)8512026-09-18 13:10:03.611 UTC [665] ERROR: relation "goose_db_version" does not exist at character 368522026-09-18 13:10:03.611 UTC [665] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8532026-09-18 13:10:03.612 UTC [666] ERROR: relation "goose_db_version" does not exist at character 368542026-09-18 13:10:03.612 UTC [666] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8552026/09/18 13:10:03 OK 2_object_stats_trigger.sql (2.73ms)8562026/09/18 13:10:03 goose: up to current file version: 28572026-09-18 13:10:03.614 UTC [667] ERROR: relation "goose_db_version" does not exist at character 368582026-09-18 13:10:03.614 UTC [667] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8592026/09/18 13:10:03 OK 20260628120000_add_object_size_and_stats.sql (4.86ms)8602026/09/18 13:10:03 OK 20260905000000_add_claims.sql (4.32ms)8612026/09/18 13:10:03 goose: successfully migrated database to version: 202609050000008622026/09/18 13:10:03 OK 20260628120000_add_object_size_and_stats.sql (4.44ms)8632026/09/18 13:10:03 OK 20260628120000_add_object_size_and_stats.sql (5.22ms)8642026/09/18 13:10:03 OK 20260628120000_add_object_size_and_stats.sql (4.67ms)8652026/09/18 13:10:03 OK 1_commit_pending_closure.sql (2.55ms)8662026/09/18 13:10:03 INFO Received uploads request method=POST path=/api/pending_closures8672026/09/18 13:10:03 OK 20260905000000_add_claims.sql (3.85ms)8682026/09/18 13:10:03 goose: successfully migrated database to version: 202609050000008692026/09/18 13:10:03 OK 20260905000000_add_claims.sql (4.14ms)8702026/09/18 13:10:03 goose: successfully migrated database to version: 202609050000008712026/09/18 13:10:03 OK 2_object_stats_trigger.sql (2.06ms)8722026/09/18 13:10:03 goose: up to current file version: 28732026/09/18 13:10:03 OK 20260905000000_add_claims.sql (3.88ms)8742026/09/18 13:10:03 goose: successfully migrated database to version: 202609050000008752026/09/18 13:10:03 OK 20260905000000_add_claims.sql (4.1ms)8762026/09/18 13:10:03 goose: successfully migrated database to version: 202609050000008772026/09/18 13:10:03 OK 1_commit_pending_closure.sql (1.95ms)8782026/09/18 13:10:03 OK 1_commit_pending_closure.sql (2.1ms)8792026/09/18 13:10:03 OK 1_commit_pending_closure.sql (1.79ms)8802026/09/18 13:10:03 OK 20241026095416_initial_model.sql (9.8ms)8812026/09/18 13:10:03 OK 2_object_stats_trigger.sql (1.19ms)8822026/09/18 13:10:03 goose: up to current file version: 28832026/09/18 13:10:03 OK 2_object_stats_trigger.sql (1.32ms)8842026/09/18 13:10:03 goose: up to current file version: 28852026/09/18 13:10:03 OK 2_object_stats_trigger.sql (1.7ms)8862026/09/18 13:10:03 goose: up to current file version: 28872026/09/18 13:10:03 OK 1_commit_pending_closure.sql (2.32ms)8882026/09/18 13:10:03 OK 20241026095416_initial_model.sql (10.91ms)8892026/09/18 13:10:03 OK 20241026095416_initial_model.sql (11.07ms)8902026/09/18 13:10:03 OK 20251210153512_drop_unused_gin_index.sql (1.66ms)8912026/09/18 13:10:03 OK 20241026095416_initial_model.sql (11.52ms)8922026/09/18 13:10:03 OK 20241026095416_initial_model.sql (9.96ms)8932026/09/18 13:10:03 OK 2_object_stats_trigger.sql (1.45ms)8942026/09/18 13:10:03 goose: up to current file version: 28952026/09/18 13:10:03 OK 20241026095416_initial_model.sql (10.34ms)8962026/09/18 13:10:03 OK 20251210153512_drop_unused_gin_index.sql (1.72ms)8972026/09/18 13:10:03 OK 20251210153512_drop_unused_gin_index.sql (1.64ms)8982026/09/18 13:10:03 OK 20251210153512_drop_unused_gin_index.sql (1.54ms)8992026/09/18 13:10:03 OK 20251210153512_drop_unused_gin_index.sql (1.76ms)9002026/09/18 13:10:03 OK 20251218171726_add_pins.sql (2.63ms)9012026/09/18 13:10:03 OK 20251210153512_drop_unused_gin_index.sql (1.73ms)9022026/09/18 13:10:03 OK 20241026095416_initial_model.sql (10.59ms)9032026/09/18 13:10:03 OK 20251218171726_add_pins.sql (2.92ms)9042026/09/18 13:10:03 OK 20251218171726_add_pins.sql (3.52ms)9052026/09/18 13:10:03 OK 20251218171726_add_pins.sql (3.08ms)9062026/09/18 13:10:03 OK 20251210153512_drop_unused_gin_index.sql (1.49ms)9072026/09/18 13:10:03 OK 20260628120000_add_object_size_and_stats.sql (3.3ms)9082026/09/18 13:10:03 OK 20251218171726_add_pins.sql (3.18ms)9092026/09/18 13:10:03 OK 20251218171726_add_pins.sql (3.66ms)9102026/09/18 13:10:03 OK 20260628120000_add_object_size_and_stats.sql (3.01ms)9112026/09/18 13:10:03 OK 20241026095416_initial_model.sql (11.15ms)9122026/09/18 13:10:03 OK 20241026095416_initial_model.sql (13.25ms)9132026/09/18 13:10:03 OK 20241026095416_initial_model.sql (10.92ms)9142026/09/18 13:10:03 OK 20260905000000_add_claims.sql (3.14ms)9152026/09/18 13:10:03 goose: successfully migrated database to version: 202609050000009162026/09/18 13:10:03 OK 20260628120000_add_object_size_and_stats.sql (4.14ms)9172026/09/18 13:10:03 OK 20260628120000_add_object_size_and_stats.sql (3.42ms)9182026/09/18 13:10:03 OK 20251218171726_add_pins.sql (4.03ms)9192026/09/18 13:10:03 OK 20260628120000_add_object_size_and_stats.sql (3.33ms)9202026/09/18 13:10:03 OK 20260628120000_add_object_size_and_stats.sql (4.22ms)9212026/09/18 13:10:03 OK 20251210153512_drop_unused_gin_index.sql (1.36ms)9222026/09/18 13:10:03 OK 20260905000000_add_claims.sql (2.39ms)9232026/09/18 13:10:03 goose: successfully migrated database to version: 202609050000009242026/09/18 13:10:03 OK 20251210153512_drop_unused_gin_index.sql (1.41ms)9252026/09/18 13:10:03 OK 20251210153512_drop_unused_gin_index.sql (1.53ms)9262026/09/18 13:10:03 OK 1_commit_pending_closure.sql (1.94ms)9272026/09/18 13:10:03 OK 1_commit_pending_closure.sql (1.77ms)9282026/09/18 13:10:03 OK 20260905000000_add_claims.sql (3.25ms)9292026/09/18 13:10:03 goose: successfully migrated database to version: 202609050000009302026/09/18 13:10:03 OK 20260905000000_add_claims.sql (2.91ms)9312026/09/18 13:10:03 goose: successfully migrated database to version: 202609050000009322026/09/18 13:10:03 OK 2_object_stats_trigger.sql (1.39ms)9332026/09/18 13:10:03 goose: up to current file version: 29342026/09/18 13:10:03 OK 20260628120000_add_object_size_and_stats.sql (3.04ms)9352026/09/18 13:10:03 OK 20260905000000_add_claims.sql (3.16ms)9362026/09/18 13:10:03 goose: successfully migrated database to version: 202609050000009372026/09/18 13:10:03 OK 20251218171726_add_pins.sql (2.54ms)9382026/09/18 13:10:03 OK 2_object_stats_trigger.sql (735.74µs)9392026/09/18 13:10:03 goose: up to current file version: 29402026/09/18 13:10:03 OK 20260905000000_add_claims.sql (2.86ms)9412026/09/18 13:10:03 goose: successfully migrated database to version: 202609050000009422026/09/18 13:10:03 OK 20251218171726_add_pins.sql (2.8ms)9432026/09/18 13:10:03 OK 20251218171726_add_pins.sql (2.9ms)9442026/09/18 13:10:03 OK 1_commit_pending_closure.sql (1.55ms)9452026/09/18 13:10:03 OK 1_commit_pending_closure.sql (2.07ms)9462026/09/18 13:10:03 OK 1_commit_pending_closure.sql (2.48ms)9472026/09/18 13:10:03 OK 1_commit_pending_closure.sql (2.35ms)9482026/09/18 13:10:03 OK 2_object_stats_trigger.sql (773.05µs)9492026/09/18 13:10:03 goose: up to current file version: 29502026/09/18 13:10:03 OK 20260905000000_add_claims.sql (2.91ms)9512026/09/18 13:10:03 goose: successfully migrated database to version: 202609050000009522026/09/18 13:10:03 OK 2_object_stats_trigger.sql (1.33ms)9532026/09/18 13:10:03 goose: up to current file version: 29542026/09/18 13:10:03 OK 20260628120000_add_object_size_and_stats.sql (2.99ms)9552026/09/18 13:10:03 OK 20260628120000_add_object_size_and_stats.sql (2.86ms)9562026/09/18 13:10:03 INFO Received cleanup request method=DELETE path=/api/pending_closures9572026/09/18 13:10:03 OK 20260628120000_add_object_size_and_stats.sql (2.69ms)9582026/09/18 13:10:03 OK 2_object_stats_trigger.sql (887.44µs)9592026/09/18 13:10:03 goose: up to current file version: 29602026/09/18 13:10:03 OK 2_object_stats_trigger.sql (951.61µs)9612026/09/18 13:10:03 goose: up to current file version: 29622026/09/18 13:10:03 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst9632026/09/18 13:10:03 INFO Received uploads request method=POST path=/api/pending_closures9642026/09/18 13:10:03 OK 1_commit_pending_closure.sql (1.91ms)965--- PASS: TestPresignedUploadRegisteredBeforeCommit (0.50s)966=== CONT TestReadProxyNarinfo9672026/09/18 13:10:03 OK 20260905000000_add_claims.sql (2.34ms)9682026/09/18 13:10:03 goose: successfully migrated database to version: 202609050000009692026/09/18 13:10:03 OK 20260905000000_add_claims.sql (2.49ms)9702026/09/18 13:10:03 goose: successfully migrated database to version: 202609050000009712026/09/18 13:10:03 OK 2_object_stats_trigger.sql (919.11µs)9722026/09/18 13:10:03 goose: up to current file version: 29732026/09/18 13:10:03 OK 20260905000000_add_claims.sql (3.04ms)9742026/09/18 13:10:03 goose: successfully migrated database to version: 202609050000009752026/09/18 13:10:03 OK 1_commit_pending_closure.sql (1.24ms)9762026/09/18 13:10:03 OK 1_commit_pending_closure.sql (1.39ms)9772026/09/18 13:10:03 OK 2_object_stats_trigger.sql (717.43µs)9782026/09/18 13:10:03 goose: up to current file version: 29792026/09/18 13:10:03 OK 2_object_stats_trigger.sql (818.01µs)9802026/09/18 13:10:03 goose: up to current file version: 29812026/09/18 13:10:03 OK 1_commit_pending_closure.sql (1.55ms)9822026/09/18 13:10:03 OK 2_object_stats_trigger.sql (647.81µs)9832026/09/18 13:10:03 goose: up to current file version: 29842026/09/18 13:10:03 INFO Aborted multipart uploads count=09852026/09/18 13:10:03 INFO Received uploads request method=POST path=/api/pending_closures9862026/09/18 13:10:03 INFO Received cleanup request method=DELETE path=/api/pending_closures9872026/09/18 13:10:03 INFO Aborted multipart uploads count=19882026/09/18 13:10:03 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete9892026-09-18 13:10:03.663 UTC [642] ERROR: Closure does not exist: id=19902026-09-18 13:10:03.663 UTC [642] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 16 at RAISE9912026-09-18 13:10:03.663 UTC [642] STATEMENT: -- name: CommitPendingClosure :exec992 SELECT commit_pending_closure($1::bigint)993 994--- PASS: TestService_cleanupPendingClosuresHandler (0.53s)995=== CONT TestIsValidCachePath996=== RUN TestIsValidCachePath/narinfo997=== PAUSE TestIsValidCachePath/narinfo998=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars999=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars1000=== RUN TestIsValidCachePath/nar_zst1001=== PAUSE TestIsValidCachePath/nar_zst1002=== RUN TestIsValidCachePath/nar_xz1003=== PAUSE TestIsValidCachePath/nar_xz1004=== RUN TestIsValidCachePath/nar_bz21005=== PAUSE TestIsValidCachePath/nar_bz21006=== RUN TestIsValidCachePath/nar_uncompressed1007=== PAUSE TestIsValidCachePath/nar_uncompressed1008=== RUN TestIsValidCachePath/ls1009=== PAUSE TestIsValidCachePath/ls1010=== RUN TestIsValidCachePath/log1011=== PAUSE TestIsValidCachePath/log1012=== RUN TestIsValidCachePath/realisation1013=== PAUSE TestIsValidCachePath/realisation1014=== RUN TestIsValidCachePath/nix-cache-info1015=== PAUSE TestIsValidCachePath/nix-cache-info1016=== RUN TestIsValidCachePath/index.html1017=== PAUSE TestIsValidCachePath/index.html1018=== RUN TestIsValidCachePath/traversal_parent1019=== PAUSE TestIsValidCachePath/traversal_parent1020=== RUN TestIsValidCachePath/traversal_in_middle1021=== PAUSE TestIsValidCachePath/traversal_in_middle1022=== RUN TestIsValidCachePath/invalid_char_e1023=== PAUSE TestIsValidCachePath/invalid_char_e1024=== RUN TestIsValidCachePath/invalid_char_u1025=== PAUSE TestIsValidCachePath/invalid_char_u1026=== RUN TestIsValidCachePath/random_path1027=== PAUSE TestIsValidCachePath/random_path1028=== RUN TestIsValidCachePath/empty1029=== PAUSE TestIsValidCachePath/empty1030=== RUN TestIsValidCachePath/leading_slash1031=== PAUSE TestIsValidCachePath/leading_slash1032=== RUN TestIsValidCachePath/wrong_extension1033=== PAUSE TestIsValidCachePath/wrong_extension1034=== RUN TestIsValidCachePath/short_hash1035=== PAUSE TestIsValidCachePath/short_hash1036=== CONT TestParseSingleRange1037=== RUN TestParseSingleRange/none1038=== PAUSE TestParseSingleRange/none1039=== RUN TestParseSingleRange/unknown_unit1040=== PAUSE TestParseSingleRange/unknown_unit1041=== RUN TestParseSingleRange/multi-range_ignored1042=== PAUSE TestParseSingleRange/multi-range_ignored1043=== RUN TestParseSingleRange/malformed_no_dash1044=== PAUSE TestParseSingleRange/malformed_no_dash1045=== RUN TestParseSingleRange/malformed_both_empty1046=== PAUSE TestParseSingleRange/malformed_both_empty1047=== RUN TestParseSingleRange/malformed_end_before_start1048=== PAUSE TestParseSingleRange/malformed_end_before_start1049=== RUN TestParseSingleRange/closed1050=== PAUSE TestParseSingleRange/closed1051=== RUN TestParseSingleRange/open-ended1052=== PAUSE TestParseSingleRange/open-ended1053=== RUN TestParseSingleRange/end_clamped_to_size1054=== PAUSE TestParseSingleRange/end_clamped_to_size1055=== RUN TestParseSingleRange/suffix1056=== PAUSE TestParseSingleRange/suffix1057=== RUN TestParseSingleRange/suffix_exceeds_size1058=== PAUSE TestParseSingleRange/suffix_exceeds_size1059=== RUN TestParseSingleRange/single_byte1060=== PAUSE TestParseSingleRange/single_byte1061=== RUN TestParseSingleRange/start_past_EOF1062=== PAUSE TestParseSingleRange/start_past_EOF1063=== RUN TestParseSingleRange/start_far_past_EOF1064=== PAUSE TestParseSingleRange/start_far_past_EOF1065=== CONT TestResurrectedObjectNotDeleted1066--- PASS: TestReadProxyRangeRequest (0.53s)1067=== CONT TestOrphanedObjectsGCStressTest10682026/09/18 13:10:03 INFO Received uploads request method=POST path=/api/pending_closures1069--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.56s)1070=== CONT TestOrphanedObjectsGC10712026/09/18 13:10:03 INFO Received uploads request method=POST path=/api/pending_closures10722026/09/18 13:10:03 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"1073--- PASS: TestService_AuthMiddleware (0.58s)1074=== CONT TestObjectStatsTrigger1075--- PASS: TestService_Rustfstest (0.60s)1076=== CONT TestMultipartCleanup10772026-09-18 13:10:03.758 UTC [680] ERROR: relation "goose_db_version" does not exist at character 3610782026-09-18 13:10:03.758 UTC [680] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10792026/09/18 13:10:03 INFO Received uploads request method=POST path=/api/pending_closures10802026/09/18 13:10:03 INFO Received uploads request method=POST path=/api/pending_closures10812026/09/18 13:10:03 INFO Received uploads request method=POST path=/api/pending_closures10822026/09/18 13:10:03 OK 20241026095416_initial_model.sql (8.9ms)10832026-09-18 13:10:03.777 UTC [681] ERROR: relation "goose_db_version" does not exist at character 3610842026-09-18 13:10:03.777 UTC [681] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10852026/09/18 13:10:03 OK 20251210153512_drop_unused_gin_index.sql (2ms)10862026/09/18 13:10:03 OK 20251218171726_add_pins.sql (2.54ms)10872026-09-18 13:10:03.782 UTC [682] ERROR: relation "goose_db_version" does not exist at character 3610882026-09-18 13:10:03.782 UTC [682] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10892026/09/18 13:10:03 OK 20260628120000_add_object_size_and_stats.sql (3.23ms)10902026/09/18 13:10:03 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10912026/09/18 13:10:03 OK 20260905000000_add_claims.sql (4.07ms)10922026/09/18 13:10:03 goose: successfully migrated database to version: 2026090500000010932026/09/18 13:10:03 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst1094--- PASS: TestCompleteMultipartUnregistered (0.66s)1095=== CONT TestServerTLSConfig10962026/09/18 13:10:03 OK 20241026095416_initial_model.sql (9.72ms)1097=== RUN TestServerTLSConfig/no_client_CA1098=== PAUSE TestServerTLSConfig/no_client_CA1099=== RUN TestServerTLSConfig/missing_CA_file1100=== PAUSE TestServerTLSConfig/missing_CA_file1101=== RUN TestServerTLSConfig/not_a_PEM_file1102=== PAUSE TestServerTLSConfig/not_a_PEM_file1103=== CONT TestService_NativeMTLS11042026/09/18 13:10:03 OK 1_commit_pending_closure.sql (4.67ms)11052026/09/18 13:10:03 OK 20251210153512_drop_unused_gin_index.sql (2.13ms)11062026/09/18 13:10:03 OK 2_object_stats_trigger.sql (1.55ms)11072026/09/18 13:10:03 goose: up to current file version: 211082026/09/18 13:10:03 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11092026/09/18 13:10:03 OK 20241026095416_initial_model.sql (8.26ms)11102026/09/18 13:10:03 OK 20251218171726_add_pins.sql (3.29ms)11112026/09/18 13:10:03 OK 20251210153512_drop_unused_gin_index.sql (2.09ms)11122026/09/18 13:10:03 OK 20251218171726_add_pins.sql (3.5ms)11132026/09/18 13:10:03 OK 20260628120000_add_object_size_and_stats.sql (4.28ms)11142026/09/18 13:10:03 OK 20260628120000_add_object_size_and_stats.sql (3.57ms)11152026/09/18 13:10:03 OK 20260905000000_add_claims.sql (3.02ms)11162026/09/18 13:10:03 goose: successfully migrated database to version: 2026090500000011172026-09-18 13:10:03.808 UTC [686] ERROR: relation "goose_db_version" does not exist at character 3611182026-09-18 13:10:03.808 UTC [686] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11192026/09/18 13:10:03 OK 1_commit_pending_closure.sql (2.48ms)11202026/09/18 13:10:03 OK 20260905000000_add_claims.sql (3.24ms)11212026/09/18 13:10:03 goose: successfully migrated database to version: 2026090500000011222026/09/18 13:10:03 OK 2_object_stats_trigger.sql (1.36ms)11232026/09/18 13:10:03 goose: up to current file version: 211242026/09/18 13:10:03 INFO Received uploads request method=POST path=/api/pending_closures11252026/09/18 13:10:03 OK 1_commit_pending_closure.sql (14.51ms)11262026/09/18 13:10:03 OK 2_object_stats_trigger.sql (3.17ms)11272026/09/18 13:10:03 goose: up to current file version: 211282026/09/18 13:10:03 INFO Received uploads request method=POST path=/api/pending_closures11292026-09-18 13:10:03.835 UTC [687] ERROR: relation "goose_db_version" does not exist at character 3611302026-09-18 13:10:03.835 UTC [687] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11312026-09-18 13:10:03.836 UTC [688] ERROR: relation "goose_db_version" does not exist at character 3611322026-09-18 13:10:03.836 UTC [688] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11332026/09/18 13:10:03 OK 20241026095416_initial_model.sql (9.11ms)11342026/09/18 13:10:03 OK 20251210153512_drop_unused_gin_index.sql (1.79ms)11352026/09/18 13:10:03 OK 20251218171726_add_pins.sql (2.18ms)11362026/09/18 13:10:03 OK 20260628120000_add_object_size_and_stats.sql (4.14ms)11372026/09/18 13:10:03 OK 20260905000000_add_claims.sql (3.22ms)11382026/09/18 13:10:03 goose: successfully migrated database to version: 2026090500000011392026/09/18 13:10:03 OK 20241026095416_initial_model.sql (9ms)11402026/09/18 13:10:03 OK 20241026095416_initial_model.sql (8.64ms)11412026/09/18 13:10:03 OK 1_commit_pending_closure.sql (1.7ms)11422026/09/18 13:10:03 OK 20251210153512_drop_unused_gin_index.sql (1.11ms)11432026/09/18 13:10:03 OK 20251210153512_drop_unused_gin_index.sql (1.28ms)11442026/09/18 13:10:03 OK 2_object_stats_trigger.sql (978.56µs)11452026/09/18 13:10:03 goose: up to current file version: 211462026/09/18 13:10:03 OK 20251218171726_add_pins.sql (2.28ms)11472026/09/18 13:10:03 OK 20251218171726_add_pins.sql (2.28ms)11482026/09/18 13:10:03 OK 20260628120000_add_object_size_and_stats.sql (2.84ms)11492026/09/18 13:10:03 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11502026/09/18 13:10:03 OK 20260628120000_add_object_size_and_stats.sql (2.72ms)11512026/09/18 13:10:03 OK 20260905000000_add_claims.sql (2.75ms)11522026/09/18 13:10:03 goose: successfully migrated database to version: 2026090500000011532026/09/18 13:10:03 OK 20260905000000_add_claims.sql (3.05ms)11542026/09/18 13:10:03 goose: successfully migrated database to version: 2026090500000011552026/09/18 13:10:03 OK 1_commit_pending_closure.sql (2.22ms)11562026/09/18 13:10:03 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=ODVlYjNmMjgtN2U0NC00MmJiLThmZTAtZTNhNzJmMzc5MWVmLjA1MDY3MDQ0LTU0MDMtNDEzNC04OTJlLTQ4Yjc4MTQwMTU2OXgxNzg5NzM3MDAzODI5NTE1ODE211572026/09/18 13:10:03 OK 1_commit_pending_closure.sql (2.01ms)11582026/09/18 13:10:03 OK 2_object_stats_trigger.sql (1.2ms)1159--- PASS: TestReadProxyRootRedirectsToIndexHTML (0.72s)11602026/09/18 13:10:03 goose: up to current file version: 21161=== CONT TestMetricsInventory11622026/09/18 13:10:03 OK 2_object_stats_trigger.sql (1.04ms)11632026/09/18 13:10:03 goose: up to current file version: 211642026/09/18 13:10:03 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=ODVlYjNmMjgtN2U0NC00MmJiLThmZTAtZTNhNzJmMzc5MWVmLjA1MDY3MDQ0LTU0MDMtNDEzNC04OTJlLTQ4Yjc4MTQwMTU2OXgxNzg5NzM3MDAzODI5NTE1ODE2 parts=11165--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (0.73s)1166=== CONT TestNARDeduplicationMetadataUploadBug11672026-09-18 13:10:03.880 UTC [692] ERROR: relation "goose_db_version" does not exist at character 3611682026-09-18 13:10:03.880 UTC [692] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1169--- PASS: TestReadProxyInvalidPath (0.67s)1170=== CONT TestGCTaskStore_GetEmpty1171--- PASS: TestGCTaskStore_GetEmpty (0.00s)1172=== CONT TestCacheConfigHandlerMaxNarSize1173--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)1174=== CONT TestGenerateLandingPage1175--- PASS: TestGenerateLandingPage (0.01s)1176=== CONT TestService_readinessHandler11772026/09/18 13:10:03 OK 20241026095416_initial_model.sql (9.29ms)11782026/09/18 13:10:03 OK 20251210153512_drop_unused_gin_index.sql (1.85ms)11792026/09/18 13:10:03 OK 20251218171726_add_pins.sql (3.08ms)11802026/09/18 13:10:03 OK 20260628120000_add_object_size_and_stats.sql (4.1ms)11812026/09/18 13:10:03 OK 20260905000000_add_claims.sql (3.22ms)11822026/09/18 13:10:03 goose: successfully migrated database to version: 2026090500000011832026/09/18 13:10:03 OK 1_commit_pending_closure.sql (2.19ms)11842026/09/18 13:10:03 OK 2_object_stats_trigger.sql (1.63ms)11852026/09/18 13:10:03 goose: up to current file version: 21186--- PASS: TestReadProxyNarinfoAlreadyDecompressed (0.61s)1187=== CONT TestService_healthCheckHandler1188--- PASS: TestReadProxyHead (0.74s)1189=== CONT TestGracefulShutdownDrainsInflight11902026/09/18 13:10:03 INFO Starting HTTP server address=127.0.0.1:4384311912026/09/18 13:10:03 INFO Shutdown signal received, draining in-flight requests timeout=10s11922026-09-18 13:10:03.970 UTC [699] ERROR: relation "goose_db_version" does not exist at character 3611932026-09-18 13:10:03.970 UTC [699] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1194--- PASS: TestReadProxyNarStreaming (0.75s)1195=== CONT TestGCTaskStore_Fail1196--- PASS: TestGCTaskStore_Fail (0.00s)1197=== CONT TestGCTaskStore_PhaseUpdates1198--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)1199=== CONT TestGCTaskStore_CompletedAllowsNewTask1200--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)1201=== CONT TestGCTaskStore_GetReturnsLatest1202--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)1203=== CONT TestGCBugBareHashReferences12042026-09-18 13:10:03.979 UTC [701] ERROR: relation "goose_db_version" does not exist at character 3612052026-09-18 13:10:03.979 UTC [701] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12062026/09/18 13:10:03 OK 20241026095416_initial_model.sql (10ms)12072026/09/18 13:10:03 OK 20251210153512_drop_unused_gin_index.sql (1.76ms)12082026/09/18 13:10:03 OK 20251218171726_add_pins.sql (3.12ms)12092026/09/18 13:10:03 OK 20241026095416_initial_model.sql (8.39ms)12102026/09/18 13:10:03 OK 20260628120000_add_object_size_and_stats.sql (4.75ms)1211--- PASS: TestReadRedirectNar (0.85s)12122026/09/18 13:10:03 OK 20251210153512_drop_unused_gin_index.sql (2.08ms)1213=== CONT TestGCTaskStore_ConflictDifferentParams1214--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)1215=== CONT TestGCTaskStore_DeduplicateSameParams1216--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)1217=== CONT TestGCTaskStore_StartNew1218--- PASS: TestGCTaskStore_StartNew (0.00s)1219=== CONT TestClientErrorHandling1220=== RUN TestClientErrorHandling/InvalidStorePath1221=== PAUSE TestClientErrorHandling/InvalidStorePath1222=== RUN TestClientErrorHandling/InvalidAuthToken1223=== PAUSE TestClientErrorHandling/InvalidAuthToken1224=== RUN TestClientErrorHandling/ServerNotAvailable1225=== PAUSE TestClientErrorHandling/ServerNotAvailable1226=== CONT TestGCMetrics12272026/09/18 13:10:03 OK 20260905000000_add_claims.sql (3.17ms)12282026/09/18 13:10:03 goose: successfully migrated database to version: 2026090500000012292026/09/18 13:10:03 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12302026-09-18 13:10:03.999 UTC [703] ERROR: relation "goose_db_version" does not exist at character 3612312026-09-18 13:10:03.999 UTC [703] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12322026/09/18 13:10:04 OK 20251218171726_add_pins.sql (3.23ms)12332026/09/18 13:10:04 OK 1_commit_pending_closure.sql (2.49ms)12342026/09/18 13:10:04 OK 2_object_stats_trigger.sql (1.23ms)12352026/09/18 13:10:04 goose: up to current file version: 212362026/09/18 13:10:04 OK 20260628120000_add_object_size_and_stats.sql (4.13ms)12372026/09/18 13:10:04 OK 20260905000000_add_claims.sql (2.61ms)12382026/09/18 13:10:04 goose: successfully migrated database to version: 2026090500000012392026/09/18 13:10:04 OK 1_commit_pending_closure.sql (2.03ms)12402026/09/18 13:10:04 OK 2_object_stats_trigger.sql (1.57ms)12412026/09/18 13:10:04 goose: up to current file version: 212422026/09/18 13:10:04 OK 20241026095416_initial_model.sql (8.19ms)12432026/09/18 13:10:04 OK 20251210153512_drop_unused_gin_index.sql (2.16ms)12442026-09-18 13:10:04.019 UTC [721] ERROR: relation "goose_db_version" does not exist at character 3612452026-09-18 13:10:04.019 UTC [721] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1246--- PASS: TestReadProxyDisabled (0.88s)12472026/09/18 13:10:04 OK 20251218171726_add_pins.sql (3.02ms)1248=== CONT TestResolveDBConnectionString1249=== RUN TestResolveDBConnectionString/flag_wins1250=== PAUSE TestResolveDBConnectionString/flag_wins1251=== RUN TestResolveDBConnectionString/file_when_flag_empty1252=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1253--- PASS: TestGracefulShutdownDrainsInflight (0.07s)1254=== RUN TestResolveDBConnectionString/missing_file_is_an_error1255=== CONT TestClaim_TooManyStreams1256=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1257=== RUN TestResolveDBConnectionString/PGHOST_allows_empty1258=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1259=== RUN TestResolveDBConnectionString/nothing_configured1260=== PAUSE TestResolveDBConnectionString/nothing_configured1261=== CONT TestPinProtectsFromGC12622026/09/18 13:10:04 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=ODVlYjNmMjgtN2U0NC00MmJiLThmZTAtZTNhNzJmMzc5MWVmLjZkODJjMmIyLTg3OWItNGIwNi1hYTk0LTlmMzgzMzYxNjYwY3gxNzg5NzM3MDAzNTk5NTYyNDY1 parts=1012632026/09/18 13:10:04 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete12642026/09/18 13:10:04 OK 20260628120000_add_object_size_and_stats.sql (3.66ms)12652026/09/18 13:10:04 INFO Completed upload id=112662026/09/18 13:10:04 OK 20260905000000_add_claims.sql (4.02ms)12672026/09/18 13:10:04 goose: successfully migrated database to version: 2026090500000012682026/09/18 13:10:04 INFO Received uploads request method=POST path=/api/pending_closures12692026/09/18 13:10:04 OK 1_commit_pending_closure.sql (2.52ms)12702026/09/18 13:10:04 INFO Received uploads request method=POST path=/api/pending_closures12712026/09/18 13:10:04 OK 2_object_stats_trigger.sql (1.64ms)12722026/09/18 13:10:04 goose: up to current file version: 212732026/09/18 13:10:04 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo12742026/09/18 13:10:04 WARN Found objects in DB but missing from S3, will re-upload count=112752026/09/18 13:10:04 OK 20241026095416_initial_model.sql (8.32ms)12762026/09/18 13:10:04 OK 20251210153512_drop_unused_gin_index.sql (1.91ms)1277--- PASS: TestService_verifyS3Integrity (0.90s)1278=== CONT TestClientCADerivations12792026/09/18 13:10:04 OK 20251218171726_add_pins.sql (3.22ms)12802026/09/18 13:10:04 OK 20260628120000_add_object_size_and_stats.sql (3.41ms)12812026/09/18 13:10:04 OK 20260905000000_add_claims.sql (2.89ms)12822026/09/18 13:10:04 goose: successfully migrated database to version: 2026090500000012832026/09/18 13:10:04 OK 1_commit_pending_closure.sql (2.15ms)12842026/09/18 13:10:04 OK 2_object_stats_trigger.sql (2.19ms)12852026/09/18 13:10:04 goose: up to current file version: 21286--- PASS: TestReadProxyConditionalGet (0.91s)1287=== CONT TestClientWithDependencies12882026/09/18 13:10:04 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1289--- PASS: TestReadRedirectKeepsNarinfoProxied (0.94s)12902026-09-18 13:10:04.079 UTC [730] ERROR: relation "goose_db_version" does not exist at character 3612912026-09-18 13:10:04.079 UTC [730] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1292=== CONT TestPresent12932026/09/18 13:10:04 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=ODVlYjNmMjgtN2U0NC00MmJiLThmZTAtZTNhNzJmMzc5MWVmLmYxMjhmY2Q3LTZmODItNDAzYy05YzM0LTg2Zjg2M2M1YjBhZXgxNzg5NzM3MDAzNjAzOTA2NjYy parts=121294--- PASS: TestRedundantMultipartUpload (0.96s)1295=== CONT TestClaim_StreamsThroughServer12962026/09/18 13:10:04 OK 20241026095416_initial_model.sql (12.64ms)12972026-09-18 13:10:04.102 UTC [733] ERROR: relation "goose_db_version" does not exist at character 3612982026-09-18 13:10:04.102 UTC [733] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12992026/09/18 13:10:04 OK 20251210153512_drop_unused_gin_index.sql (2.3ms)13002026/09/18 13:10:04 OK 20251218171726_add_pins.sql (3.59ms)13012026/09/18 13:10:04 OK 20260628120000_add_object_size_and_stats.sql (4.99ms)1302--- PASS: TestReadRedirectUsesPublicS3URL (0.97s)1303=== CONT TestClientMultipleUploads13042026/09/18 13:10:04 OK 20260905000000_add_claims.sql (4.09ms)13052026/09/18 13:10:04 goose: successfully migrated database to version: 2026090500000013062026/09/18 13:10:04 OK 20241026095416_initial_model.sql (10.31ms)13072026/09/18 13:10:04 OK 1_commit_pending_closure.sql (2.34ms)13082026/09/18 13:10:04 OK 20251210153512_drop_unused_gin_index.sql (2.49ms)13092026/09/18 13:10:04 OK 2_object_stats_trigger.sql (1.98ms)13102026/09/18 13:10:04 goose: up to current file version: 21311--- PASS: TestReadProxy404 (0.92s)1312=== CONT TestClaim_InputsTouched13132026/09/18 13:10:04 OK 20251218171726_add_pins.sql (18.02ms)13142026/09/18 13:10:04 OK 20260628120000_add_object_size_and_stats.sql (5.89ms)13152026/09/18 13:10:04 OK 20260905000000_add_claims.sql (4.91ms)13162026/09/18 13:10:04 goose: successfully migrated database to version: 2026090500000013172026-09-18 13:10:04.151 UTC [740] ERROR: relation "goose_db_version" does not exist at character 3613182026-09-18 13:10:04.151 UTC [740] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13192026-09-18 13:10:04.151 UTC [741] ERROR: relation "goose_db_version" does not exist at character 3613202026-09-18 13:10:04.151 UTC [741] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13212026/09/18 13:10:04 OK 1_commit_pending_closure.sql (2.68ms)13222026/09/18 13:10:04 OK 2_object_stats_trigger.sql (1.81ms)13232026/09/18 13:10:04 goose: up to current file version: 213242026-09-18 13:10:04.159 UTC [742] ERROR: relation "goose_db_version" does not exist at character 3613252026-09-18 13:10:04.159 UTC [742] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13262026/09/18 13:10:04 OK 20241026095416_initial_model.sql (10.97ms)13272026/09/18 13:10:04 OK 20241026095416_initial_model.sql (11.04ms)1328--- PASS: TestReadProxyNarinfo (0.53s)1329=== CONT TestClientIntegration13302026/09/18 13:10:04 OK 20251210153512_drop_unused_gin_index.sql (1.99ms)13312026/09/18 13:10:04 OK 20251210153512_drop_unused_gin_index.sql (3.06ms)13322026/09/18 13:10:04 OK 20251218171726_add_pins.sql (3.61ms)13332026/09/18 13:10:04 OK 20251218171726_add_pins.sql (3.58ms)13342026-09-18 13:10:04.177 UTC [744] ERROR: relation "goose_db_version" does not exist at character 3613352026-09-18 13:10:04.177 UTC [744] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13362026/09/18 13:10:04 OK 20241026095416_initial_model.sql (10.85ms)13372026/09/18 13:10:04 OK 20260628120000_add_object_size_and_stats.sql (3.7ms)13382026/09/18 13:10:04 OK 20260628120000_add_object_size_and_stats.sql (3.33ms)13392026/09/18 13:10:04 OK 20251210153512_drop_unused_gin_index.sql (1.73ms)13402026/09/18 13:10:04 OK 20260905000000_add_claims.sql (2.9ms)13412026/09/18 13:10:04 goose: successfully migrated database to version: 2026090500000013422026/09/18 13:10:04 OK 20260905000000_add_claims.sql (2.98ms)13432026/09/18 13:10:04 goose: successfully migrated database to version: 2026090500000013442026/09/18 13:10:04 OK 20251218171726_add_pins.sql (3.63ms)13452026/09/18 13:10:04 OK 1_commit_pending_closure.sql (2.55ms)13462026/09/18 13:10:04 OK 1_commit_pending_closure.sql (2.81ms)13472026/09/18 13:10:04 OK 2_object_stats_trigger.sql (2.13ms)13482026/09/18 13:10:04 goose: up to current file version: 213492026/09/18 13:10:04 OK 2_object_stats_trigger.sql (1.92ms)13502026/09/18 13:10:04 goose: up to current file version: 213512026/09/18 13:10:04 OK 20260628120000_add_object_size_and_stats.sql (4.18ms)13522026/09/18 13:10:04 OK 20260905000000_add_claims.sql (4.29ms)13532026/09/18 13:10:04 goose: successfully migrated database to version: 2026090500000013542026/09/18 13:10:04 OK 20241026095416_initial_model.sql (11.04ms)13552026/09/18 13:10:04 OK 1_commit_pending_closure.sql (3.2ms)13562026/09/18 13:10:04 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13572026-09-18 13:10:04.197 UTC [746] ERROR: relation "goose_db_version" does not exist at character 3613582026-09-18 13:10:04.197 UTC [746] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13592026/09/18 13:10:04 OK 20251210153512_drop_unused_gin_index.sql (14.03ms)13602026/09/18 13:10:04 OK 2_object_stats_trigger.sql (17.32ms)13612026/09/18 13:10:04 goose: up to current file version: 213622026/09/18 13:10:04 OK 20251218171726_add_pins.sql (6.46ms)13632026/09/18 13:10:04 OK 20260628120000_add_object_size_and_stats.sql (6.01ms)13642026/09/18 13:10:04 OK 20241026095416_initial_model.sql (9.22ms)13652026-09-18 13:10:04.222 UTC [747] ERROR: relation "goose_db_version" does not exist at character 3613662026-09-18 13:10:04.222 UTC [747] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13672026/09/18 13:10:04 OK 20260905000000_add_claims.sql (3.28ms)13682026/09/18 13:10:04 goose: successfully migrated database to version: 2026090500000013692026/09/18 13:10:04 OK 20251210153512_drop_unused_gin_index.sql (2.18ms)13702026/09/18 13:10:04 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=ODVlYjNmMjgtN2U0NC00MmJiLThmZTAtZTNhNzJmMzc5MWVmLmMyMzNhMzg4LWNlNzktNGZiYS1hMDU4LTE2NzBlZTBmYjYxY3gxNzg5NzM3MDAzNzc1MDE2Mzg5 parts=1013712026/09/18 13:10:04 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete13722026/09/18 13:10:04 OK 1_commit_pending_closure.sql (1.93ms)13732026/09/18 13:10:04 OK 20251218171726_add_pins.sql (2.67ms)13742026/09/18 13:10:04 OK 2_object_stats_trigger.sql (1.52ms)13752026/09/18 13:10:04 goose: up to current file version: 213762026/09/18 13:10:04 INFO Completed upload id=113772026/09/18 13:10:04 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000013782026/09/18 13:10:04 OK 20260628120000_add_object_size_and_stats.sql (3.4ms)13792026/09/18 13:10:04 INFO Received uploads request method=POST path=/api/pending_closures13802026/09/18 13:10:04 OK 20260905000000_add_claims.sql (2.73ms)13812026/09/18 13:10:04 goose: successfully migrated database to version: 2026090500000013822026/09/18 13:10:04 INFO Starting cleanup of old closures method=DELETE path=/api/closures13832026/09/18 13:10:04 OK 1_commit_pending_closure.sql (2.52ms)13842026/09/18 13:10:04 OK 2_object_stats_trigger.sql (1.26ms)13852026/09/18 13:10:04 goose: up to current file version: 213862026-09-18 13:10:04.238 UTC [748] ERROR: relation "goose_db_version" does not exist at character 3613872026-09-18 13:10:04.238 UTC [748] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13882026/09/18 13:10:04 OK 20241026095416_initial_model.sql (8.88ms)13892026/09/18 13:10:04 OK 20251210153512_drop_unused_gin_index.sql (1.68ms)13902026-09-18 13:10:04.241 UTC [749] ERROR: relation "goose_db_version" does not exist at character 3613912026-09-18 13:10:04.241 UTC [749] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13922026/09/18 13:10:04 OK 20251218171726_add_pins.sql (3.38ms)13932026/09/18 13:10:04 INFO Aborted multipart uploads count=013942026/09/18 13:10:04 OK 20260628120000_add_object_size_and_stats.sql (3.26ms)13952026/09/18 13:10:04 OK 20260905000000_add_claims.sql (2.71ms)13962026/09/18 13:10:04 goose: successfully migrated database to version: 2026090500000013972026/09/18 13:10:04 OK 1_commit_pending_closure.sql (2.19ms)13982026/09/18 13:10:04 OK 2_object_stats_trigger.sql (1.6ms)13992026/09/18 13:10:04 goose: up to current file version: 214002026/09/18 13:10:04 OK 20241026095416_initial_model.sql (9.57ms)14012026/09/18 13:10:04 OK 20251210153512_drop_unused_gin_index.sql (1.35ms)14022026/09/18 13:10:04 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=014032026/09/18 13:10:04 OK 20241026095416_initial_model.sql (8.97ms)14042026/09/18 13:10:04 OK 20251218171726_add_pins.sql (2.75ms)14052026/09/18 13:10:04 OK 20251210153512_drop_unused_gin_index.sql (1.45ms)14062026/09/18 13:10:04 INFO Vacuumed table table=pending_closures14072026/09/18 13:10:04 OK 20260628120000_add_object_size_and_stats.sql (3.65ms)14082026/09/18 13:10:04 OK 20251218171726_add_pins.sql (3.55ms)14092026/09/18 13:10:04 INFO Vacuumed table table=pending_objects1410--- PASS: TestResurrectedObjectNotDeleted (0.60s)1411=== CONT TestClaim_TwoInstances14122026/09/18 13:10:04 OK 20260905000000_add_claims.sql (6.63ms)14132026/09/18 13:10:04 goose: successfully migrated database to version: 2026090500000014142026/09/18 13:10:04 OK 20260628120000_add_object_size_and_stats.sql (6.55ms)14152026/09/18 13:10:04 INFO Vacuumed table table=multipart_uploads14162026/09/18 13:10:04 OK 1_commit_pending_closure.sql (1.82ms)14172026/09/18 13:10:04 OK 20260905000000_add_claims.sql (2.04ms)14182026/09/18 13:10:04 goose: successfully migrated database to version: 2026090500000014192026/09/18 13:10:04 INFO Vacuumed table table=closures14202026/09/18 13:10:04 OK 2_object_stats_trigger.sql (573.1µs)14212026/09/18 13:10:04 goose: up to current file version: 214222026/09/18 13:10:04 INFO Vacuumed table table=objects14232026/09/18 13:10:04 OK 1_commit_pending_closure.sql (1.88ms)14242026/09/18 13:10:04 OK 2_object_stats_trigger.sql (674.15µs)14252026/09/18 13:10:04 goose: up to current file version: 214262026-09-18 13:10:04.278 UTC [753] ERROR: relation "goose_db_version" does not exist at character 3614272026-09-18 13:10:04.278 UTC [753] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14282026/09/18 13:10:04 INFO Received uploads request method=POST path=/api/pending_closures14292026/09/18 13:10:04 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001430--- PASS: TestService_createPendingClosureHandler (1.15s)1431=== CONT TestClaim_StaleHeartbeatStolen14322026/09/18 13:10:04 OK 20241026095416_initial_model.sql (8ms)14332026/09/18 13:10:04 OK 20251210153512_drop_unused_gin_index.sql (2.57ms)14342026/09/18 13:10:04 OK 20251218171726_add_pins.sql (3.27ms)14352026/09/18 13:10:04 OK 20260628120000_add_object_size_and_stats.sql (3.64ms)14362026/09/18 13:10:04 OK 20260905000000_add_claims.sql (2.87ms)14372026/09/18 13:10:04 goose: successfully migrated database to version: 2026090500000014382026/09/18 13:10:04 OK 1_commit_pending_closure.sql (2.13ms)14392026/09/18 13:10:04 OK 2_object_stats_trigger.sql (1.49ms)14402026/09/18 13:10:04 goose: up to current file version: 21441--- PASS: TestObjectStatsTrigger (0.62s)1442=== CONT TestClaim_HolderDisconnectKeepsClaim14432026/09/18 13:10:04 WARN mTLS auth: subject not in bound subjects subject="CN=reader"14442026/09/18 13:10:04 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1445--- PASS: TestService_NativeMTLS (0.55s)1446=== CONT TestClaim_FailWakesWaitersButIsNotRemembered14472026-09-18 13:10:04.360 UTC [760] ERROR: relation "goose_db_version" does not exist at character 3614482026-09-18 13:10:04.360 UTC [760] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14492026/09/18 13:10:04 INFO Received complete multipart upload request method=POST path=/api/multipart/complete14502026/09/18 13:10:04 OK 20241026095416_initial_model.sql (8.24ms)14512026/09/18 13:10:04 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=ODVlYjNmMjgtN2U0NC00MmJiLThmZTAtZTNhNzJmMzc5MWVmLjRmNGI3NDNlLTQ3MmYtNDAyNC1iYzczLWE1MDM0Zjg2NjFmMngxNzg5NzM3MDAzODQyNzIxOTc2 parts=1214522026/09/18 13:10:04 OK 20251210153512_drop_unused_gin_index.sql (1.8ms)14532026/09/18 13:10:04 INFO Received uploads request method=POST path=/api/pending_closures14542026/09/18 13:10:04 OK 20251218171726_add_pins.sql (2.85ms)14552026-09-18 13:10:04.393 UTC [761] ERROR: relation "goose_db_version" does not exist at character 3614562026-09-18 13:10:04.393 UTC [761] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1457--- PASS: TestCompletedNarNotReofferedAcrossClosures (1.25s)1458=== CONT TestClaim_FailWithoutKindReleases14592026/09/18 13:10:04 OK 20260628120000_add_object_size_and_stats.sql (3.01ms)14602026/09/18 13:10:04 OK 20260905000000_add_claims.sql (3ms)14612026/09/18 13:10:04 goose: successfully migrated database to version: 2026090500000014622026/09/18 13:10:04 INFO Received cleanup request method=DELETE path=/api/pending_closures14632026/09/18 13:10:04 OK 1_commit_pending_closure.sql (2.61ms)14642026/09/18 13:10:04 OK 2_object_stats_trigger.sql (1.83ms)14652026/09/18 13:10:04 goose: up to current file version: 21466--- PASS: TestMetricsInventory (0.54s)1467=== CONT TestService_ReadScope_PublicByDefault14682026/09/18 13:10:04 INFO Aborted multipart uploads count=114692026/09/18 13:10:04 OK 20241026095416_initial_model.sql (8.63ms)14702026/09/18 13:10:04 OK 20251210153512_drop_unused_gin_index.sql (1.79ms)1471--- PASS: TestMultipartCleanup (0.67s)1472=== CONT TestClaim_BuildWaitComplete14732026/09/18 13:10:04 OK 20251218171726_add_pins.sql (2.98ms)14742026/09/18 13:10:04 OK 20260628120000_add_object_size_and_stats.sql (4.41ms)14752026/09/18 13:10:04 OK 20260905000000_add_claims.sql (3.52ms)14762026/09/18 13:10:04 goose: successfully migrated database to version: 2026090500000014772026/09/18 13:10:04 OK 1_commit_pending_closure.sql (4.83ms)14782026/09/18 13:10:04 OK 2_object_stats_trigger.sql (1.63ms)14792026/09/18 13:10:04 goose: up to current file version: 214802026/09/18 13:10:04 WARN readiness check failed error="closed pool"1481--- PASS: TestService_readinessHandler (0.54s)1482=== CONT TestClaim_GCMarkedOutputCountsAsAbsent1483=== NAME TestNARDeduplicationMetadataUploadBug1484 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug3009276683/001/store/vmi1hg6a3hhgciy8nmalw6gizn242p42-file1.txt14852026-09-18 13:10:04.444 UTC [787] ERROR: relation "goose_db_version" does not exist at character 3614862026-09-18 13:10:04.444 UTC [787] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14872026-09-18 13:10:04.446 UTC [788] ERROR: relation "goose_db_version" does not exist at character 3614882026-09-18 13:10:04.446 UTC [788] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1489--- PASS: TestService_healthCheckHandler (0.53s)1490=== CONT TestCacheStatsHandler14912026/09/18 13:10:04 OK 20241026095416_initial_model.sql (18.58ms)14922026/09/18 13:10:04 OK 20241026095416_initial_model.sql (20.39ms)14932026/09/18 13:10:04 OK 20251210153512_drop_unused_gin_index.sql (5.07ms)14942026/09/18 13:10:04 OK 20251210153512_drop_unused_gin_index.sql (2.85ms)14952026/09/18 13:10:04 OK 20251218171726_add_pins.sql (3.64ms)14962026/09/18 13:10:04 OK 20251218171726_add_pins.sql (3.64ms)14972026/09/18 13:10:04 OK 20260628120000_add_object_size_and_stats.sql (3.7ms)14982026/09/18 13:10:04 OK 20260628120000_add_object_size_and_stats.sql (5.15ms)14992026/09/18 13:10:04 OK 20260905000000_add_claims.sql (3.62ms)15002026/09/18 13:10:04 goose: successfully migrated database to version: 2026090500000015012026/09/18 13:10:04 OK 1_commit_pending_closure.sql (2.49ms)15022026/09/18 13:10:04 OK 20260905000000_add_claims.sql (4.84ms)15032026/09/18 13:10:04 goose: successfully migrated database to version: 2026090500000015042026/09/18 13:10:04 OK 2_object_stats_trigger.sql (2.27ms)15052026/09/18 13:10:04 goose: up to current file version: 215062026/09/18 13:10:04 OK 1_commit_pending_closure.sql (3.28ms)15072026/09/18 13:10:04 OK 2_object_stats_trigger.sql (1.88ms)15082026/09/18 13:10:04 goose: up to current file version: 215092026-09-18 13:10:04.501 UTC [809] ERROR: relation "goose_db_version" does not exist at character 3615102026-09-18 13:10:04.501 UTC [809] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15112026-09-18 13:10:04.512 UTC [810] ERROR: relation "goose_db_version" does not exist at character 3615122026-09-18 13:10:04.512 UTC [810] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15132026/09/18 13:10:04 OK 20241026095416_initial_model.sql (8.4ms)15142026/09/18 13:10:04 OK 20251210153512_drop_unused_gin_index.sql (1.69ms)15152026-09-18 13:10:04.518 UTC [812] ERROR: relation "goose_db_version" does not exist at character 3615162026-09-18 13:10:04.518 UTC [812] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15172026/09/18 13:10:04 OK 20251218171726_add_pins.sql (4.31ms)15182026/09/18 13:10:04 INFO Aborted multipart uploads count=015192026/09/18 13:10:04 WARN Force mode enabled - objects will be deleted immediately without grace period15202026/09/18 13:10:04 OK 20260628120000_add_object_size_and_stats.sql (4.06ms)15212026/09/18 13:10:04 OK 20241026095416_initial_model.sql (8.7ms)15222026/09/18 13:10:04 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=015232026/09/18 13:10:04 INFO Vacuumed table table=pending_closures15242026/09/18 13:10:04 INFO Vacuumed table table=pending_objects15252026-09-18 13:10:04.529 UTC [814] ERROR: relation "goose_db_version" does not exist at character 3615262026-09-18 13:10:04.529 UTC [814] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15272026/09/18 13:10:04 OK 20251210153512_drop_unused_gin_index.sql (1.92ms)15282026/09/18 13:10:04 INFO Vacuumed table table=multipart_uploads15292026/09/18 13:10:04 INFO Vacuumed table table=closures15302026/09/18 13:10:04 OK 20260905000000_add_claims.sql (3.85ms)15312026/09/18 13:10:04 goose: successfully migrated database to version: 2026090500000015322026/09/18 13:10:04 INFO Vacuumed table table=objects15332026/09/18 13:10:04 OK 20241026095416_initial_model.sql (8.56ms)15342026/09/18 13:10:04 OK 20251218171726_add_pins.sql (3.24ms)15352026/09/18 13:10:04 OK 1_commit_pending_closure.sql (2.55ms)15362026/09/18 13:10:04 OK 20251210153512_drop_unused_gin_index.sql (2.25ms)15372026/09/18 13:10:04 OK 2_object_stats_trigger.sql (2.44ms)15382026/09/18 13:10:04 goose: up to current file version: 215392026/09/18 13:10:04 OK 20260628120000_add_object_size_and_stats.sql (3.5ms)15402026/09/18 13:10:04 WARN claim: cannot clear write deadline error="feature not supported"15412026/09/18 13:10:04 OK 20251218171726_add_pins.sql (2.58ms)15422026/09/18 13:10:04 OK 20260905000000_add_claims.sql (2.78ms)15432026/09/18 13:10:04 goose: successfully migrated database to version: 202609050000001544--- PASS: TestGCMetrics (0.54s)1545=== CONT TestCacheConfigHandler1546=== RUN TestCacheConfigHandler/full_config,_no_issuer1547=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1548=== RUN TestCacheConfigHandler/no_cache_url_configured1549=== PAUSE TestCacheConfigHandler/no_cache_url_configured1550=== RUN TestCacheConfigHandler/no_signing_keys1551=== PAUSE TestCacheConfigHandler/no_signing_keys15522026/09/18 13:10:04 OK 20260628120000_add_object_size_and_stats.sql (2.87ms)1553=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1554=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1555=== CONT TestService_ReadAuthMiddleware15562026/09/18 13:10:04 OK 1_commit_pending_closure.sql (1.45ms)15572026/09/18 13:10:04 OK 2_object_stats_trigger.sql (1.16ms)15582026/09/18 13:10:04 goose: up to current file version: 215592026/09/18 13:10:04 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"15602026/09/18 13:10:04 OK 20260905000000_add_claims.sql (10.14ms)15612026/09/18 13:10:04 goose: successfully migrated database to version: 2026090500000015622026/09/18 13:10:04 OK 20241026095416_initial_model.sql (15.75ms)1563--- PASS: TestClaim_TooManyStreams (0.53s)1564=== CONT TestService_AuthMiddleware_MTLSBoundSubjects15652026/09/18 13:10:04 OK 20251210153512_drop_unused_gin_index.sql (1.04ms)15662026/09/18 13:10:04 OK 1_commit_pending_closure.sql (1.64ms)15672026/09/18 13:10:04 OK 2_object_stats_trigger.sql (1.2ms)15682026/09/18 13:10:04 goose: up to current file version: 215692026/09/18 13:10:04 OK 20251218171726_add_pins.sql (2.88ms)15702026/09/18 13:10:04 OK 20260628120000_add_object_size_and_stats.sql (3.35ms)15712026-09-18 13:10:04.561 UTC [837] ERROR: relation "goose_db_version" does not exist at character 3615722026-09-18 13:10:04.561 UTC [837] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15732026/09/18 13:10:04 OK 20260905000000_add_claims.sql (4.5ms)15742026/09/18 13:10:04 goose: successfully migrated database to version: 2026090500000015752026/09/18 13:10:04 OK 1_commit_pending_closure.sql (2.26ms)15762026/09/18 13:10:04 OK 2_object_stats_trigger.sql (2.15ms)15772026/09/18 13:10:04 goose: up to current file version: 21578=== NAME TestOrphanedObjectsGC1579 orphaned_objects_gc_test.go:290: GC Test Summary:1580 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A1581 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B1582 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)1583 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)1584 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects1585--- PASS: TestOrphanedObjectsGC (0.88s)1586=== CONT TestService_RequireScope_OIDC15872026/09/18 13:10:04 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:33149/oidc15882026/09/18 13:10:04 OK 20241026095416_initial_model.sql (9.74ms)15892026/09/18 13:10:04 OK 20251210153512_drop_unused_gin_index.sql (1.92ms)15902026/09/18 13:10:04 OK 20251218171726_add_pins.sql (3.42ms)15912026/09/18 13:10:04 OK 20260628120000_add_object_size_and_stats.sql (3.46ms)15922026/09/18 13:10:04 INFO Received uploads request method=POST path=/api/pending_closures15932026/09/18 13:10:04 OK 20260905000000_add_claims.sql (2.97ms)15942026/09/18 13:10:04 goose: successfully migrated database to version: 2026090500000015952026/09/18 13:10:04 OK 1_commit_pending_closure.sql (2.37ms)15962026/09/18 13:10:04 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15972026/09/18 13:10:04 INFO Uploading vmi1hg6a3hhgciy8nmalw6gizn242p42-file1.txt (160B)15982026/09/18 13:10:04 OK 2_object_stats_trigger.sql (2.04ms)15992026/09/18 13:10:04 goose: up to current file version: 216002026/09/18 13:10:04 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"16012026/09/18 13:10:04 WARN Failed to register uploaded object key=vmi1hg6a3hhgciy8nmalw6gizn242p42.ls error="server returned 404: 404 page not found\n"16022026/09/18 13:10:04 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign16032026/09/18 13:10:04 INFO Signed narinfos id=1 count=116042026/09/18 13:10:04 INFO Uploading 1 narinfos16052026/09/18 13:10:04 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete16062026/09/18 13:10:04 WARN Failed to register uploaded object key=vmi1hg6a3hhgciy8nmalw6gizn242p42.narinfo error="server returned 404: 404 page not found\n"16072026/09/18 13:10:04 INFO Completed upload id=116082026/09/18 13:10:04 INFO Upload complete. (109ms)1609=== NAME TestNARDeduplicationMetadataUploadBug1610 metadata_upload_test.go:54: Retrieved narinfo from S3:1611 StorePath: /build/TestNARDeduplicationMetadataUploadBug3009276683/001/store/vmi1hg6a3hhgciy8nmalw6gizn242p42-file1.txt1612 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1613 Compression: zstd1614 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1615 NarSize: 1601616 References: 1617 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1618 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1619 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1620 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}16212026/09/18 13:10:04 INFO Received uploads request method=POST path=/api/pending_closures16222026-09-18 13:10:04.630 UTC [911] ERROR: relation "goose_db_version" does not exist at character 3616232026-09-18 13:10:04.630 UTC [911] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1624=== NAME TestPinProtectsFromGC1625 client_integration_test.go:667: Pinned store path: /build/TestPinProtectsFromGC2517412808/001/store/7307cbsis9pikjh2p62jj17cm0rsa8n1-pinned-file.txt1626 client_integration_test.go:668: Unpinned store path: /build/TestPinProtectsFromGC2517412808/001/store/72vx698h23yq7dgwn39x7y140j887zf0-unpinned-file.txt16272026/09/18 13:10:04 OK 20241026095416_initial_model.sql (8.04ms)16282026-09-18 13:10:04.644 UTC [931] ERROR: relation "goose_db_version" does not exist at character 3616292026-09-18 13:10:04.644 UTC [931] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16302026/09/18 13:10:04 OK 20251210153512_drop_unused_gin_index.sql (1.8ms)16312026/09/18 13:10:04 OK 20251218171726_add_pins.sql (3.82ms)1632=== NAME TestNARDeduplicationMetadataUploadBug1633 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug3009276683/001/store/g6kz2dbzrl6n07cd00x3irfkz6wrf52c-file2.txt16342026/09/18 13:10:04 OK 20260628120000_add_object_size_and_stats.sql (3.15ms)16352026/09/18 13:10:04 OK 20260905000000_add_claims.sql (2.88ms)16362026/09/18 13:10:04 goose: successfully migrated database to version: 2026090500000016372026/09/18 13:10:04 OK 1_commit_pending_closure.sql (2.14ms)16382026/09/18 13:10:04 OK 20241026095416_initial_model.sql (8.17ms)16392026/09/18 13:10:04 OK 2_object_stats_trigger.sql (901.59µs)16402026/09/18 13:10:04 goose: up to current file version: 216412026/09/18 13:10:04 OK 20251210153512_drop_unused_gin_index.sql (2.06ms)16422026/09/18 13:10:04 OK 20251218171726_add_pins.sql (2.56ms)16432026/09/18 13:10:04 OK 20260628120000_add_object_size_and_stats.sql (3.36ms)16442026/09/18 13:10:04 OK 20260905000000_add_claims.sql (2.88ms)16452026/09/18 13:10:04 goose: successfully migrated database to version: 2026090500000016462026/09/18 13:10:04 OK 1_commit_pending_closure.sql (1.6ms)16472026/09/18 13:10:04 OK 2_object_stats_trigger.sql (591.35µs)16482026/09/18 13:10:04 goose: up to current file version: 216492026-09-18 13:10:04.681 UTC [1033] ERROR: relation "goose_db_version" does not exist at character 3616502026-09-18 13:10:04.681 UTC [1033] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1651=== NAME TestClientCADerivations1652 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations4046656739/001/store/9d7sidgnh19hqg3yllgvklw20r4g8z2h-ca-test16532026/09/18 13:10:04 OK 20241026095416_initial_model.sql (7.08ms)16542026/09/18 13:10:04 OK 20251210153512_drop_unused_gin_index.sql (1.51ms)16552026/09/18 13:10:04 OK 20251218171726_add_pins.sql (1.77ms)16562026/09/18 13:10:04 INFO Received uploads request method=POST path=/api/pending_closures1657=== NAME TestClientWithDependencies1658 client_integration_test.go:613: Built derivation: /build/TestClientWithDependencies166546148/001/store/smc3zhrikfcxfx70mxwg7va0y0pvjb2k-test-script16592026/09/18 13:10:04 OK 20260628120000_add_object_size_and_stats.sql (2.76ms)16602026/09/18 13:10:04 OK 20260905000000_add_claims.sql (2.02ms)16612026/09/18 13:10:04 goose: successfully migrated database to version: 2026090500000016622026/09/18 13:10:04 OK 1_commit_pending_closure.sql (1.31ms)16632026/09/18 13:10:04 OK 2_object_stats_trigger.sql (735.06µs)16642026/09/18 13:10:04 goose: up to current file version: 216652026/09/18 13:10:04 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"16662026/09/18 13:10:04 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"1667=== NAME TestClientMultipleUploads1668 client_integration_test.go:358: Created store path 0: /build/TestClientMultipleUploads2720879088/001/store/v7ih8hs6spjjhnb2s9ak513k6yn25g6n-test-file-0.txt1669=== NAME TestClientCADerivations1670 client_ca_test.go:139: Found 1 dependencies (including self)1671--- PASS: TestGCBugBareHashReferences (0.75s)1672=== CONT TestService_AuthMiddleware_OIDC16732026/09/18 13:10:04 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:42553/oidc1674=== NAME TestClientWithDependencies1675 client_integration_test.go:615: Found 1 dependencies (including self)16762026/09/18 13:10:04 WARN claim: cannot clear write deadline error="feature not supported"16772026/09/18 13:10:04 INFO Received uploads request method=POST path=/api/pending_closures16782026/09/18 13:10:04 INFO Received uploads request method=POST path=/api/pending_closures1679=== NAME TestClientMultipleUploads1680 client_integration_test.go:358: Created store path 1: /build/TestClientMultipleUploads2720879088/001/store/rdrz33n2cfr3agg7cn53nnbkk11nsv85-test-file-1.txt16812026/09/18 13:10:04 WARN claim: cannot clear write deadline error="feature not supported"16822026/09/18 13:10:04 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)16832026/09/18 13:10:04 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)16842026/09/18 13:10:04 INFO Uploading 7307cbsis9pikjh2p62jj17cm0rsa8n1-pinned-file.txt (128B)16852026/09/18 13:10:04 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign16862026/09/18 13:10:04 WARN Failed to register uploaded object key=g6kz2dbzrl6n07cd00x3irfkz6wrf52c.ls error="server returned 404: 404 page not found\n"16872026/09/18 13:10:04 INFO Signed narinfos id=2 count=116882026/09/18 13:10:04 INFO Uploading 1 narinfos16892026/09/18 13:10:04 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"16902026/09/18 13:10:04 WARN claim: cannot clear write deadline error="feature not supported"1691=== NAME TestClientIntegration1692 client_integration_test.go:286: Created store path: /build/TestClientIntegration3503833587/002/store/dd8lxwpdxlpycw9680bj52fc1l63b0jm-test-file.txt16932026/09/18 13:10:04 INFO Received uploads request method=POST path=/api/pending_closures16942026/09/18 13:10:04 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign16952026/09/18 13:10:04 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete16962026/09/18 13:10:04 WARN Failed to register uploaded object key=7307cbsis9pikjh2p62jj17cm0rsa8n1.ls error="server returned 404: 404 page not found\n"16972026/09/18 13:10:04 INFO Signed narinfos id=1 count=116982026/09/18 13:10:04 WARN Failed to register uploaded object key=g6kz2dbzrl6n07cd00x3irfkz6wrf52c.narinfo error="server returned 404: 404 page not found\n"16992026/09/18 13:10:04 INFO Uploading 1 narinfos17002026/09/18 13:10:04 INFO Completed upload id=217012026/09/18 13:10:04 INFO Upload complete. (82ms)1702=== NAME TestNARDeduplicationMetadataUploadBug1703 metadata_upload_test.go:76: Retrieved narinfo from S3:1704 StorePath: /build/TestNARDeduplicationMetadataUploadBug3009276683/001/store/g6kz2dbzrl6n07cd00x3irfkz6wrf52c-file2.txt1705 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1706 Compression: zstd1707 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1708 NarSize: 1601709 References: 17102026/09/18 13:10:04 WARN claim: cannot clear write deadline error="feature not supported"1711 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf17122026/09/18 13:10:04 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete17132026/09/18 13:10:04 WARN Failed to register uploaded object key=7307cbsis9pikjh2p62jj17cm0rsa8n1.narinfo error="server returned 404: 404 page not found\n"1714 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1715 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1716 {"version":1,"root":{"type":"regular","size":44}}1717--- PASS: TestNARDeduplicationMetadataUploadBug (0.90s)1718=== CONT TestService_AuthMiddleware_MTLSProxyHeader17192026/09/18 13:10:04 INFO Completed upload id=117202026/09/18 13:10:04 INFO Upload complete. (101ms)17212026/09/18 13:10:04 WARN claim: cannot clear write deadline error="feature not supported"1722--- PASS: TestClaim_StaleHeartbeatStolen (0.50s)1723=== CONT TestProxyWriteTimeout/narinfo1724=== CONT TestProxyWriteTimeout/unknown_size1725=== CONT TestProxyWriteTimeout/10_GiB_nar1726=== CONT TestProxyWriteTimeout/1_GiB_nar1727--- PASS: TestProxyWriteTimeout (0.00s)1728 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1729 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1730 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1731 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1732=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info17332026/09/18 13:10:04 INFO Received uploads request method=POST path=/1734=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key17352026/09/18 13:10:04 INFO Received complete multipart upload request method=POST path=/1736=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key17372026/09/18 13:10:04 INFO Received request for more parts method=POST path=/1738=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal17392026/09/18 13:10:04 INFO Received uploads request method=POST path=/1740--- PASS: TestUploadHandlersRejectInvalidKeys (0.08s)1741 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1742 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1743 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1744 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1745=== CONT TestIsValidUploadKey/narinfo1746=== CONT TestIsValidUploadKey/realisation_plus_in_output1747=== CONT TestIsValidUploadKey/realisation1748=== CONT TestIsValidUploadKey/build_log_equals1749=== CONT TestIsValidUploadKey/build_log_question_mark1750=== CONT TestIsValidUploadKey/build_log_plus_in_name1751=== CONT TestIsValidUploadKey/nix-cache-info1752=== CONT TestIsValidUploadKey/build_log_home-manager_file1753=== CONT TestIsValidUploadKey/build_log1754=== CONT TestIsValidUploadKey/listing1755=== CONT TestIsValidUploadKey/nar_plain1756=== CONT TestIsValidUploadKey/nar_xz1757=== CONT TestIsValidUploadKey/nar_zst1758=== CONT TestIsValidUploadKey/traversal1759=== CONT TestIsValidUploadKey/unknown_type1760=== CONT TestIsValidUploadKey/empty_key1761=== CONT TestIsValidUploadKey/absolute1762=== CONT TestIsValidUploadKey/traversal_nar1763=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1764=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1765=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1766=== CONT TestIsValidUploadKey/index.html1767--- PASS: TestIsValidUploadKey (0.08s)1768 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1769 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1770 --- PASS: TestIsValidUploadKey/realisation (0.00s)1771 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1772 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1773 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1774 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1775 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1776 --- PASS: TestIsValidUploadKey/build_log (0.00s)1777 --- PASS: TestIsValidUploadKey/listing (0.00s)1778 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1779 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1780 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1781 --- PASS: TestIsValidUploadKey/traversal (0.00s)1782 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1783 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1784 --- PASS: TestIsValidUploadKey/absolute (0.00s)1785 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1786 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1787 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1788 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1789 --- PASS: TestIsValidUploadKey/index.html (0.00s)1790=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure17912026/09/18 13:10:04 INFO Received uploads request method=POST path=/17922026/09/18 13:10:04 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"1793=== NAME TestClientMultipleUploads1794 client_integration_test.go:358: Created store path 2: /build/TestClientMultipleUploads2720879088/001/store/6sw0mvbx5czbwh1kjp7fb8i478nz46cw-test-file-2.txt17952026/09/18 13:10:04 WARN claim: cannot clear write deadline error="feature not supported"17962026/09/18 13:10:04 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"17972026-09-18 13:10:04.799 UTC [1312] ERROR: relation "goose_db_version" does not exist at character 3617982026-09-18 13:10:04.799 UTC [1312] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17992026/09/18 13:10:04 INFO Received uploads request method=POST path=/api/pending_closures18002026/09/18 13:10:04 WARN claim: cannot clear write deadline error="feature not supported"18012026/09/18 13:10:04 WARN claim: cannot clear write deadline error="feature not supported"1802--- PASS: TestClaim_FailWakesWaitersButIsNotRemembered (0.46s)1803=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts18042026/09/18 13:10:04 INFO Received request for more parts method=POST path=/18052026/09/18 13:10:04 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)18062026/09/18 13:10:04 INFO Uploading smc3zhrikfcxfx70mxwg7va0y0pvjb2k-test-script (136B)18072026/09/18 13:10:04 WARN Failed to register uploaded object key=log/q23vbji0gvsb3dhzp1dyjrqd9gcq4fr0-test-script.drv error="server returned 404: 404 page not found\n"18082026/09/18 13:10:04 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"18092026/09/18 13:10:04 OK 20241026095416_initial_model.sql (7.73ms)18102026/09/18 13:10:04 OK 20251210153512_drop_unused_gin_index.sql (3.07ms)18112026/09/18 13:10:04 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign18122026/09/18 13:10:04 WARN Failed to register uploaded object key=smc3zhrikfcxfx70mxwg7va0y0pvjb2k.ls error="server returned 404: 404 page not found\n"18132026/09/18 13:10:04 INFO Signed narinfos id=1 count=118142026/09/18 13:10:04 INFO Uploading 1 narinfos18152026/09/18 13:10:04 OK 20251218171726_add_pins.sql (2.38ms)18162026/09/18 13:10:04 WARN claim: cannot clear write deadline error="feature not supported"18172026/09/18 13:10:04 OK 20260628120000_add_object_size_and_stats.sql (2.94ms)18182026/09/18 13:10:04 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete18192026/09/18 13:10:04 INFO Received uploads request method=POST path=/api/pending_closures18202026/09/18 13:10:04 WARN Failed to register uploaded object key=smc3zhrikfcxfx70mxwg7va0y0pvjb2k.narinfo error="server returned 404: 404 page not found\n"18212026/09/18 13:10:04 OK 20260905000000_add_claims.sql (2.7ms)18222026/09/18 13:10:04 goose: successfully migrated database to version: 2026090500000018232026/09/18 13:10:04 OK 1_commit_pending_closure.sql (2.15ms)18242026/09/18 13:10:04 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)18252026/09/18 13:10:04 INFO Uploading 9d7sidgnh19hqg3yllgvklw20r4g8z2h-ca-test (144B)18262026/09/18 13:10:04 OK 2_object_stats_trigger.sql (1.64ms)18272026/09/18 13:10:04 goose: up to current file version: 218282026/09/18 13:10:04 INFO Completed upload id=118292026/09/18 13:10:04 INFO Upload complete. (69ms)18302026/09/18 13:10:04 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"18312026/09/18 13:10:04 WARN Failed to register uploaded object key=log/cpjyrhiinm62pah64nj666pvcdkkviww-ca-test.drv error="server returned 404: 404 page not found\n"1832=== NAME TestClientWithDependencies1833 client_integration_test.go:617: Skipping nix copy test - isolated store (/build/TestClientWithDependencies166546148/001/store) requires matching store prefix18342026/09/18 13:10:04 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"18352026/09/18 13:10:04 WARN claim: cannot clear write deadline error="feature not supported"18362026/09/18 13:10:04 WARN Failed to register uploaded object key=9d7sidgnh19hqg3yllgvklw20r4g8z2h.ls error="server returned 404: 404 page not found\n"18372026/09/18 13:10:04 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign18382026/09/18 13:10:04 INFO Signed narinfos id=1 count=118392026/09/18 13:10:04 INFO Uploading 1 narinfos1840--- PASS: TestClientWithDependencies (0.79s)1841=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart18422026/09/18 13:10:04 INFO Received complete multipart upload request method=POST path=/18432026/09/18 13:10:04 WARN claim: cannot clear write deadline error="feature not supported"18442026/09/18 13:10:04 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete18452026/09/18 13:10:04 WARN Failed to register uploaded object key=9d7sidgnh19hqg3yllgvklw20r4g8z2h.narinfo error="server returned 404: 404 page not found\n"18462026/09/18 13:10:04 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"18472026/09/18 13:10:04 INFO Completed upload id=118482026/09/18 13:10:04 INFO Upload complete. (99ms)1849=== NAME TestClientCADerivations1850 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations4046656739/001/store/9d7sidgnh19hqg3yllgvklw20r4g8z2h-ca-test1851 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1852 Compression: zstd1853 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1854 NarSize: 1441855 References: 1856 Deriver: /build/TestClientCADerivations4046656739/001/store/cpjyrhiinm62pah64nj666pvcdkkviww-ca-test.drv1857 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1858 client_ca_test.go:185: Checking for realisation files in S3...18592026/09/18 13:10:04 WARN claim: cannot clear write deadline error="feature not supported"1860 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1861 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache1862--- PASS: TestClaim_FailWithoutKindReleases (0.46s)1863=== CONT TestIsValidCachePath/narinfo1864=== CONT TestIsValidCachePath/index.html1865=== CONT TestIsValidCachePath/short_hash1866=== CONT TestIsValidCachePath/wrong_extension1867=== CONT TestIsValidCachePath/leading_slash1868=== CONT TestIsValidCachePath/empty1869=== CONT TestIsValidCachePath/random_path1870=== CONT TestIsValidCachePath/invalid_char_u1871=== CONT TestIsValidCachePath/invalid_char_e1872=== CONT TestIsValidCachePath/traversal_in_middle1873=== CONT TestIsValidCachePath/nar_uncompressed1874=== CONT TestIsValidCachePath/nix-cache-info1875=== CONT TestIsValidCachePath/realisation1876=== CONT TestIsValidCachePath/log1877=== CONT TestIsValidCachePath/ls1878=== CONT TestIsValidCachePath/nar_xz1879=== CONT TestIsValidCachePath/nar_bz21880=== CONT TestIsValidCachePath/traversal_parent1881=== CONT TestIsValidCachePath/nar_zst1882=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1883--- PASS: TestIsValidCachePath (0.00s)1884 --- PASS: TestIsValidCachePath/narinfo (0.00s)1885 --- PASS: TestIsValidCachePath/index.html (0.00s)1886 --- PASS: TestIsValidCachePath/short_hash (0.00s)1887 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1888 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1889 --- PASS: TestIsValidCachePath/empty (0.00s)1890 --- PASS: TestIsValidCachePath/random_path (0.00s)1891 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1892 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1893 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1894 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1895 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1896 --- PASS: TestIsValidCachePath/realisation (0.00s)1897 --- PASS: TestIsValidCachePath/log (0.00s)1898 --- PASS: TestIsValidCachePath/ls (0.00s)1899 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1900 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1901 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1902 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1903 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1904=== CONT TestParseSingleRange/none1905=== CONT TestParseSingleRange/open-ended1906=== CONT TestParseSingleRange/start_far_past_EOF1907=== CONT TestParseSingleRange/start_past_EOF1908=== CONT TestParseSingleRange/suffix1909=== CONT TestParseSingleRange/end_clamped_to_size1910=== CONT TestParseSingleRange/suffix_exceeds_size1911=== CONT TestParseSingleRange/single_byte1912=== CONT TestParseSingleRange/malformed_both_empty1913=== CONT TestParseSingleRange/closed1914=== CONT TestParseSingleRange/malformed_end_before_start1915=== CONT TestParseSingleRange/multi-range_ignored1916=== CONT TestParseSingleRange/malformed_no_dash1917=== CONT TestParseSingleRange/unknown_unit1918--- PASS: TestParseSingleRange (0.00s)1919 --- PASS: TestParseSingleRange/none (0.00s)1920 --- PASS: TestParseSingleRange/open-ended (0.00s)1921 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1922 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1923 --- PASS: TestParseSingleRange/suffix (0.00s)1924 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1925 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1926 --- PASS: TestParseSingleRange/single_byte (0.00s)1927 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1928 --- PASS: TestParseSingleRange/closed (0.00s)1929 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1930 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1931 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1932 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1933=== CONT TestServerTLSConfig/no_client_CA1934=== CONT TestServerTLSConfig/not_a_PEM_file1935=== CONT TestServerTLSConfig/missing_CA_file1936--- PASS: TestServerTLSConfig (0.00s)1937 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1938 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)1939 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1940=== CONT TestClientErrorHandling/InvalidStorePath19412026-09-18 13:10:04.860 UTC [1408] ERROR: relation "goose_db_version" does not exist at character 3619422026-09-18 13:10:04.860 UTC [1408] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1943--- PASS: TestService_ReadScope_PublicByDefault (0.46s)1944=== CONT TestClientErrorHandling/ServerNotAvailable19452026/09/18 13:10:04 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"19462026/09/18 13:10:04 INFO Received uploads request method=POST path=/api/pending_closures1947=== CONT TestClientErrorHandling/InvalidAuthToken19482026/09/18 13:10:04 OK 20241026095416_initial_model.sql (8.95ms)19492026/09/18 13:10:04 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)19502026/09/18 13:10:04 INFO Uploading dd8lxwpdxlpycw9680bj52fc1l63b0jm-test-file.txt (152B)19512026/09/18 13:10:04 OK 20251210153512_drop_unused_gin_index.sql (1.43ms)19522026/09/18 13:10:04 INFO Received uploads request method=POST path=/api/pending_closures19532026/09/18 13:10:04 OK 20251218171726_add_pins.sql (2.6ms)19542026/09/18 13:10:04 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"19552026/09/18 13:10:04 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)19562026/09/18 13:10:04 INFO Uploading 72vx698h23yq7dgwn39x7y140j887zf0-unpinned-file.txt (128B)19572026/09/18 13:10:04 OK 20260628120000_add_object_size_and_stats.sql (2.75ms)19582026/09/18 13:10:04 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign19592026/09/18 13:10:04 WARN Failed to register uploaded object key=dd8lxwpdxlpycw9680bj52fc1l63b0jm.ls error="server returned 404: 404 page not found\n"19602026/09/18 13:10:04 INFO Signed narinfos id=1 count=119612026/09/18 13:10:04 INFO Uploading 1 narinfos19622026/09/18 13:10:04 OK 20260905000000_add_claims.sql (3.14ms)19632026/09/18 13:10:04 goose: successfully migrated database to version: 2026090500000019642026/09/18 13:10:04 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"19652026/09/18 13:10:04 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete19662026/09/18 13:10:04 WARN Failed to register uploaded object key=dd8lxwpdxlpycw9680bj52fc1l63b0jm.narinfo error="server returned 404: 404 page not found\n"19672026/09/18 13:10:04 WARN claim: cannot clear write deadline error="feature not supported"19682026/09/18 13:10:04 OK 1_commit_pending_closure.sql (2.74ms)19692026/09/18 13:10:04 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign19702026/09/18 13:10:04 INFO Signed narinfos id=2 count=119712026/09/18 13:10:04 WARN Failed to register uploaded object key=72vx698h23yq7dgwn39x7y140j887zf0.ls error="server returned 404: 404 page not found\n"19722026/09/18 13:10:04 INFO Uploading 1 narinfos19732026/09/18 13:10:04 OK 2_object_stats_trigger.sql (1.93ms)19742026/09/18 13:10:04 goose: up to current file version: 219752026/09/18 13:10:04 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete19762026/09/18 13:10:04 WARN Failed to register uploaded object key=72vx698h23yq7dgwn39x7y140j887zf0.narinfo error="server returned 404: 404 page not found\n"19772026/09/18 13:10:04 INFO Completed upload id=219782026/09/18 13:10:04 INFO Upload complete. (81ms)19792026/09/18 13:10:04 INFO Completed upload id=119802026/09/18 13:10:04 INFO Upload complete. (103ms)19812026/09/18 13:10:04 WARN claim: cannot clear write deadline error="feature not supported"19822026/09/18 13:10:04 WARN claim: cannot clear write deadline error="feature not supported"19832026/09/18 13:10:04 INFO Received uploads request method=POST path=/api/pending_closures19842026/09/18 13:10:04 INFO Received uploads request method=POST path=/api/pending_closures19852026/09/18 13:10:04 INFO Received uploads request method=POST path=/api/pending_closures19862026/09/18 13:10:04 INFO Received uploads request method=POST path=/api/pending_closures1987=== CONT TestResolveDBConnectionString/flag_wins1988=== CONT TestResolveDBConnectionString/PGHOST_allows_empty1989=== CONT TestResolveDBConnectionString/nothing_configured1990=== CONT TestResolveDBConnectionString/missing_file_is_an_error1991=== CONT TestResolveDBConnectionString/file_when_flag_empty1992=== CONT TestCacheConfigHandler/full_config,_no_issuer1993=== CONT TestCacheConfigHandler/no_signing_keys1994--- PASS: TestResolveDBConnectionString (0.00s)1995 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)1996 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)1997 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)1998 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)1999 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)2000=== CONT TestCacheConfigHandler/no_cache_url_configured2001=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator2002--- PASS: TestCacheConfigHandler (0.00s)2003 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)2004 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)2005 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)2006 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)20072026/09/18 13:10:04 INFO Received uploads request method=POST path=/api/pending_closures20082026/09/18 13:10:04 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)20092026/09/18 13:10:04 INFO Uploading v7ih8hs6spjjhnb2s9ak513k6yn25g6n-test-file-0.txt (160B)20102026/09/18 13:10:04 INFO Uploading rdrz33n2cfr3agg7cn53nnbkk11nsv85-test-file-1.txt (160B)20112026/09/18 13:10:04 INFO Uploading 6sw0mvbx5czbwh1kjp7fb8i478nz46cw-test-file-2.txt (160B)20122026/09/18 13:10:04 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"20132026/09/18 13:10:04 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"20142026/09/18 13:10:04 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"20152026/09/18 13:10:04 WARN Failed to register uploaded object key=v7ih8hs6spjjhnb2s9ak513k6yn25g6n.ls error="server returned 404: 404 page not found\n"20162026/09/18 13:10:04 WARN Failed to register uploaded object key=rdrz33n2cfr3agg7cn53nnbkk11nsv85.ls error="server returned 404: 404 page not found\n"20172026/09/18 13:10:04 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign20182026/09/18 13:10:04 WARN Failed to register uploaded object key=6sw0mvbx5czbwh1kjp7fb8i478nz46cw.ls error="server returned 404: 404 page not found\n"20192026/09/18 13:10:04 INFO Signed narinfos id=2 count=120202026/09/18 13:10:04 INFO Received sign narinfos request method=POST path=/api/pending_closures/3/sign20212026/09/18 13:10:04 INFO Signed narinfos id=3 count=120222026/09/18 13:10:04 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign20232026/09/18 13:10:04 INFO Signed narinfos id=1 count=120242026/09/18 13:10:04 INFO Uploading 3 narinfos20252026/09/18 13:10:04 WARN Failed to register uploaded object key=6sw0mvbx5czbwh1kjp7fb8i478nz46cw.narinfo error="server returned 404: 404 page not found\n"20262026/09/18 13:10:04 WARN Failed to register uploaded object key=rdrz33n2cfr3agg7cn53nnbkk11nsv85.narinfo error="server returned 404: 404 page not found\n"20272026/09/18 13:10:04 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete20282026/09/18 13:10:04 WARN Failed to register uploaded object key=v7ih8hs6spjjhnb2s9ak513k6yn25g6n.narinfo error="server returned 404: 404 page not found\n"20292026/09/18 13:10:04 INFO All 1 paths already cached2030=== NAME TestClientIntegration2031 client_integration_test.go:312: Retrieved narinfo from S3:2032 StorePath: /build/TestClientIntegration3503833587/002/store/dd8lxwpdxlpycw9680bj52fc1l63b0jm-test-file.txt2033 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst2034 Compression: zstd2035 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk12036 NarSize: 1522037 References: 2038 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk12039 client_integration_test.go:313: Retrieved .ls file from S3 (compressed size: 77 bytes)2040 client_integration_test.go:313: Decompressed .ls content (64 bytes):2041 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}2042 client_integration_test.go:316: Testing garbage collection...20432026/09/18 13:10:04 INFO Completed upload id=120442026/09/18 13:10:04 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete2045--- PASS: TestCacheStatsHandler (0.48s)20462026/09/18 13:10:04 INFO Completed upload id=220472026/09/18 13:10:04 INFO Received complete upload request method=POST path=/api/pending_closures/3/complete20482026/09/18 13:10:04 INFO Received create pin request method=POST path=/api/pins/myapp20492026/09/18 13:10:04 INFO Completed upload id=320502026/09/18 13:10:04 INFO Upload complete. (118ms)2051=== NAME TestClientMultipleUploads2052 client_integration_test.go:369: Uploaded 3 paths in 152.142192ms20532026-09-18 13:10:04.948 UTC [1685] ERROR: relation "goose_db_version" does not exist at character 3620542026-09-18 13:10:04.948 UTC [1685] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC20552026/09/18 13:10:04 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC2517412808/001/store/7307cbsis9pikjh2p62jj17cm0rsa8n1-pinned-file.txt narinfo_key=7307cbsis9pikjh2p62jj17cm0rsa8n1.narinfo20562026/09/18 13:10:04 INFO Starting cleanup of old closures method=DELETE path=/api/closures20572026/09/18 13:10:04 INFO Garbage collection started2058--- PASS: TestClientMultipleUploads (0.84s)2059--- PASS: TestService_ReadAuthMiddleware (0.41s)20602026/09/18 13:10:04 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/present20612026/09/18 13:10:04 OK 20241026095416_initial_model.sql (7.19ms)20622026/09/18 13:10:04 INFO Aborted multipart uploads count=020632026/09/18 13:10:04 OK 20251210153512_drop_unused_gin_index.sql (1.07ms)20642026-09-18 13:10:04.962 UTC [1772] ERROR: relation "goose_db_version" does not exist at character 3620652026-09-18 13:10:04.962 UTC [1772] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC20662026/09/18 13:10:04 WARN Force mode enabled - objects will be deleted immediately without grace period20672026/09/18 13:10:04 OK 20251218171726_add_pins.sql (1.7ms)20682026/09/18 13:10:04 OK 20260628120000_add_object_size_and_stats.sql (2.48ms)20692026/09/18 13:10:04 INFO Starting cleanup of old closures method=DELETE path=/api/closures20702026/09/18 13:10:04 INFO Garbage collection started20712026/09/18 13:10:04 OK 20260905000000_add_claims.sql (2.52ms)20722026/09/18 13:10:04 goose: successfully migrated database to version: 2026090500000020732026/09/18 13:10:04 OK 1_commit_pending_closure.sql (2.35ms)20742026/09/18 13:10:04 OK 2_object_stats_trigger.sql (596.35µs)20752026/09/18 13:10:04 goose: up to current file version: 220762026/09/18 13:10:04 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"20772026/09/18 13:10:04 WARN mTLS auth: bound subjects configured but subject DN unavailable20782026/09/18 13:10:04 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"2079--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (0.42s)20802026/09/18 13:10:04 OK 20241026095416_initial_model.sql (6.85ms)20812026/09/18 13:10:04 OK 20251210153512_drop_unused_gin_index.sql (977.13µs)2082=== NAME TestClientCADerivations20832026/09/18 13:10:04 OK 20251218171726_add_pins.sql (1.98ms)2084 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features2085 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable2086 error: binary cache 's3://bucket41?endpoint=http://localhost:35087®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations4046656739/001/store'2087 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 120882026/09/18 13:10:04 INFO Aborted multipart uploads count=020892026/09/18 13:10:04 OK 20260628120000_add_object_size_and_stats.sql (2.22ms)20902026/09/18 13:10:04 WARN Force mode enabled - objects will be deleted immediately without grace period20912026/09/18 13:10:04 OK 20260905000000_add_claims.sql (2.15ms)20922026/09/18 13:10:04 goose: successfully migrated database to version: 2026090500000020932026/09/18 13:10:04 OK 1_commit_pending_closure.sql (2.04ms)2094--- PASS: TestClientCADerivations (0.95s)20952026/09/18 13:10:04 OK 2_object_stats_trigger.sql (847.66µs)20962026/09/18 13:10:04 goose: up to current file version: 22097=== RUN TestService_RequireScope_OIDC/builder_may_write2098=== PAUSE TestService_RequireScope_OIDC/builder_may_write2099=== RUN TestService_RequireScope_OIDC/builder_may_not_admin2100=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin2101=== RUN TestService_RequireScope_OIDC/ops_may_admin2102=== PAUSE TestService_RequireScope_OIDC/ops_may_admin2103=== RUN TestService_RequireScope_OIDC/ops_may_not_write2104=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write2105=== RUN TestService_RequireScope_OIDC/reader_may_not_write2106=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write2107=== RUN TestService_RequireScope_OIDC/static_token_may_admin2108=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin2109=== RUN TestService_RequireScope_OIDC/static_token_may_write2110=== PAUSE TestService_RequireScope_OIDC/static_token_may_write2111=== RUN TestService_RequireScope_OIDC/reader_may_read2112=== PAUSE TestService_RequireScope_OIDC/reader_may_read2113=== RUN TestService_RequireScope_OIDC/writer_implies_read2114=== PAUSE TestService_RequireScope_OIDC/writer_implies_read2115=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read2116=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read2117=== CONT TestService_RequireScope_OIDC/builder_may_write2118=== CONT TestService_RequireScope_OIDC/static_token_may_admin2119=== CONT TestService_RequireScope_OIDC/writer_implies_read2120=== CONT TestService_RequireScope_OIDC/static_token_may_write2121=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read2122=== CONT TestService_RequireScope_OIDC/ops_may_admin2123=== CONT TestService_RequireScope_OIDC/reader_may_read2124=== CONT TestService_RequireScope_OIDC/ops_may_not_write2125=== CONT TestService_RequireScope_OIDC/reader_may_not_write2126=== CONT TestService_RequireScope_OIDC/builder_may_not_admin21272026/09/18 13:10:05 INFO OIDC auth successful provider=test scopes=[write]21282026/09/18 13:10:05 INFO OIDC auth successful provider=test scopes=[read]21292026/09/18 13:10:05 INFO OIDC auth successful provider=test scopes=[write]21302026/09/18 13:10:05 INFO OIDC auth successful provider=test scopes=[admin]21312026/09/18 13:10:05 INFO OIDC auth successful provider=test scopes=[read]21322026/09/18 13:10:05 INFO OIDC auth successful provider=test scopes=[write]21332026/09/18 13:10:05 INFO OIDC auth successful provider=test scopes=[admin]2134--- PASS: TestService_RequireScope_OIDC (0.43s)2135 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)2136 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)2137 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)2138 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)2139 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)2140 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)2141 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)2142 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)2143 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)2144 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)2145=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token2146=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token2147=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected2148=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected2149=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected2150=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected2151=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2152=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2153=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token2154=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected2155=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected21562026/09/18 13:10:05 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]2157=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured21582026/09/18 13:10:05 INFO OIDC auth successful provider=test scopes=[write]21592026/09/18 13:10:05 WARN Authentication failed token_preview=eyJhbGciOi...XGQq_AC6sA token_length=702 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]2160--- PASS: TestService_AuthMiddleware_OIDC (0.30s)2161 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)2162 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)2163 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)2164 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)21652026/09/18 13:10:05 INFO Received complete multipart upload request method=POST path=/api/multipart/complete2166--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.27s)21672026/09/18 13:10:05 INFO Completed multipart upload object_key=nar/0000000000000000000000000000002000000000000000000000.nar.zst upload_id=ODVlYjNmMjgtN2U0NC00MmJiLThmZTAtZTNhNzJmMzc5MWVmLjdhNzZlM2RhLTdhNzUtNGY4Yi1hYmU4LWRjMDliMGI5NjNjNHgxNzg5NzM3MDA0NjQ1NzQyMjkx parts=1021682026/09/18 13:10:05 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete21692026/09/18 13:10:05 INFO Completed upload id=121702026/09/18 13:10:05 INFO Received uploads request method=POST path=/api/pending_closures21712026/09/18 13:10:05 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=185.657412ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present21722026/09/18 13:10:05 INFO Received complete multipart upload request method=POST path=/api/multipart/complete21732026/09/18 13:10:05 INFO Completed multipart upload object_key=nar/0000000000000000000000000000001700000000000000000000.nar.zst upload_id=ODVlYjNmMjgtN2U0NC00MmJiLThmZTAtZTNhNzJmMzc5MWVmLmM2MTI3NzIyLWY5MzAtNDMxNS05YzU2LTYxNzUxZGQzZTlkZngxNzg5NzM3MDA0NzEwMzI2MTIx parts=1021742026/09/18 13:10:05 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete21752026/09/18 13:10:05 INFO Completed upload id=121762026/09/18 13:10:05 WARN claim: cannot clear write deadline error="feature not supported"21772026/09/18 13:10:05 INFO Aborted multipart uploads count=021782026/09/18 13:10:05 WARN Force mode enabled - objects will be deleted immediately without grace period21792026/09/18 13:10:05 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=021802026/09/18 13:10:05 INFO Vacuumed table table=pending_closures21812026/09/18 13:10:05 INFO Vacuumed table table=pending_objects21822026/09/18 13:10:05 INFO Vacuumed table table=multipart_uploads21832026/09/18 13:10:05 INFO Vacuumed table table=closures21842026/09/18 13:10:05 INFO Vacuumed table table=objects2185--- PASS: TestClaim_InputsTouched (0.99s)21862026/09/18 13:10:05 INFO Received complete multipart upload request method=POST path=/api/multipart/complete21872026/09/18 13:10:05 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"21882026/09/18 13:10:05 INFO Completed multipart upload object_key=nar/0000000000000000000000000000001600000000000000000000.nar.zst upload_id=ODVlYjNmMjgtN2U0NC00MmJiLThmZTAtZTNhNzJmMzc5MWVmLjIyNzQ1ZDE5LWU2YTQtNDQ0ZC05MTYxLTI3YmQxOGJhNjkxMHgxNzg5NzM3MDA0NzY2MTM1NzY3 parts=1021892026/09/18 13:10:05 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign21902026/09/18 13:10:05 INFO Signed narinfos id=1 count=121912026/09/18 13:10:05 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete21922026/09/18 13:10:05 INFO Completed upload id=12193--- PASS: TestClaim_TwoInstances (0.91s)21942026/09/18 13:10:05 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"21952026/09/18 13:10:05 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"21962026/09/18 13:10:05 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=381.318487ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present21972026/09/18 13:10:05 INFO Received complete multipart upload request method=POST path=/api/multipart/complete21982026/09/18 13:10:05 INFO Completed multipart upload object_key=nar/0000000000000000000000000000001000000000000000000000.nar.zst upload_id=ODVlYjNmMjgtN2U0NC00MmJiLThmZTAtZTNhNzJmMzc5MWVmLmEwZDkwYWExLTEyMzQtNGIyOC05MjA2LTkyMWJkODgzYmNkNngxNzg5NzM3MDA0OTAxOTM3NzMx parts=1021992026/09/18 13:10:05 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign22002026/09/18 13:10:05 INFO Signed narinfos id=1 count=122012026/09/18 13:10:05 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete22022026/09/18 13:10:05 INFO Received uploads request method=POST path=/api/pending_closures22032026/09/18 13:10:05 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign22042026/09/18 13:10:05 INFO Signed narinfos id=2 count=122052026/09/18 13:10:05 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete22062026/09/18 13:10:05 INFO Received complete multipart upload request method=POST path=/api/multipart/complete22072026/09/18 13:10:05 INFO Completed upload id=222082026/09/18 13:10:05 WARN claim: cannot clear write deadline error="feature not supported"2209--- PASS: TestClaim_BuildWaitComplete (0.90s)2210--- PASS: TestUploadHandlersRejectOversizedBody (0.17s)2211 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.06s)2212 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.07s)2213 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.71s)22142026/09/18 13:10:05 WARN claim: cannot clear write deadline error="feature not supported"22152026/09/18 13:10:05 INFO Completed multipart upload object_key=nar/0000000000000000000000000000001100000000000000000000.nar.zst upload_id=ODVlYjNmMjgtN2U0NC00MmJiLThmZTAtZTNhNzJmMzc5MWVmLmYwZGNiNmYyLTA4MjItNGEwZi04MDgxLWQyOGIxY2QxYjE0MngxNzg5NzM3MDA0OTE5OTM2Nzg3 parts=1022162026/09/18 13:10:05 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete22172026/09/18 13:10:05 INFO Completed upload id=122182026/09/18 13:10:05 WARN claim: cannot clear write deadline error="feature not supported"22192026/09/18 13:10:05 WARN claim: cannot clear write deadline error="feature not supported"2220--- PASS: TestClaim_GCMarkedOutputCountsAsAbsent (1.07s)22212026/09/18 13:10:05 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=795.93129ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present22222026/09/18 13:10:05 INFO Received complete multipart upload request method=POST path=/api/multipart/complete22232026/09/18 13:10:05 INFO Completed multipart upload object_key=nar/0000000000000000000000000000002100000000000000000000.nar.zst upload_id=ODVlYjNmMjgtN2U0NC00MmJiLThmZTAtZTNhNzJmMzc5MWVmLmQ2ODU2ZDExLWUzZWMtNGNhYi05ZDA5LTk0Mjg2Y2Q1YWY5OHgxNzg5NzM3MDA1MDQ2ODIwODk5 parts=1022242026/09/18 13:10:05 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete22252026/09/18 13:10:05 INFO Completed upload id=22226--- PASS: TestPresent (1.57s)2227=== NAME TestOrphanedObjectsGCStressTest2228 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains2229 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion22302026/09/18 13:10:05 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=022312026/09/18 13:10:05 INFO Vacuumed table table=pending_closures22322026/09/18 13:10:05 INFO Vacuumed table table=pending_objects22332026/09/18 13:10:05 INFO Vacuumed table table=multipart_uploads22342026/09/18 13:10:05 INFO Vacuumed table table=closures22352026/09/18 13:10:05 INFO Vacuumed table table=objects22362026/09/18 13:10:05 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/18 13:10:05 INFO Vacuumed table table=pending_closures22382026/09/18 13:10:06 INFO Vacuumed table table=pending_objects22392026/09/18 13:10:06 INFO Vacuumed table table=multipart_uploads22402026/09/18 13:10:06 INFO Vacuumed table table=closures22412026/09/18 13:10:06 INFO Vacuumed table table=objects2242--- PASS: TestClaim_StreamsThroughServer (2.06s)2243=== NAME TestOrphanedObjectsGCStressTest2244 orphaned_objects_gc_test.go:509: Stress test completed successfully:2245 orphaned_objects_gc_test.go:510: - Active objects preserved: 202246 orphaned_objects_gc_test.go:511: - Objects deleted: 2102247 orphaned_objects_gc_test.go:512: - Total GC'd: 2102248--- PASS: TestOrphanedObjectsGCStressTest (2.52s)22492026/09/18 13:10:06 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.623413624s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present22502026/09/18 13:10:06 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=02251=== NAME TestPinProtectsFromGC2252 client_integration_test.go:730: Pin successfully protected closure from garbage collection2253--- PASS: TestPinProtectsFromGC (2.94s)22542026/09/18 13:10:06 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=02255=== NAME TestClientIntegration2256 client_integration_test.go:323: Objects in database after GC:2257 client_integration_test.go:323: Successfully deleted all objects with GC --force2258--- PASS: TestClientIntegration (2.81s)2259--- PASS: TestClaim_HolderDisconnectKeepsClaim (3.00s)22602026/09/18 13:10:07 WARN Rate limiter enabled after throttle name=s3-test rate=522612026/09/18 13:10:07 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."2262=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle2263 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=102264 throttle_test.go:215: Rate limiter: enabled=true, rate=5.002265--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (4.47s)22662026/09/18 13:10:08 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/18 13:10:08 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=216.669611ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22682026/09/18 13:10:08 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=413.814571ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22692026/09/18 13:10:08 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=751.099646ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22702026/09/18 13:10:09 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.477169402s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22712026/09/18 13:10:11 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/18 13:10:11 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/18 13:10:11 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=191.599741ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22742026/09/18 13:10:11 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=379.9964ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22752026/09/18 13:10:11 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=830.526061ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22762026/09/18 13:10:12 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.626417915s 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.24s)2279 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.36s)2280 --- PASS: TestClientErrorHandling/ServerNotAvailable (9.37s)2281PASS22822026-09-18 13:10:14.525 UTC [129] LOG: received smart shutdown request22832026-09-18 13:10:14.531 UTC [129] LOG: background worker "logical replication launcher" (PID 139) exited with exit code 122842026-09-18 13:10:14.542 UTC [134] LOG: shutting down22852026-09-18 13:10:14.543 UTC [134] LOG: checkpoint starting: shutdown immediate22862026-09-18 13:10:15.570 UTC [134] LOG: checkpoint complete: wrote 10803 buffers (65.9%), wrote 3 SLRU buffers; 0 WAL file(s) added, 0 removed, 18 recycled; write=0.242 s, sync=0.774 s, total=1.029 s; sync files=21338, longest=0.002 s, average=0.001 s; distance=287445 kB, estimate=287445 kB; lsn=0/1301B268, redo lsn=0/1301B26822872026-09-18 13:10:15.651 UTC [129] LOG: database system is shut down2288Running OIDC tests...2289=== RUN TestGlobMatch2290=== PAUSE TestGlobMatch2291=== RUN TestAudienceForIssuer2292=== PAUSE TestAudienceForIssuer2293=== RUN TestValidateToken_ValidToken2294=== PAUSE TestValidateToken_ValidToken2295=== RUN TestValidateToken_WrongAudience2296=== PAUSE TestValidateToken_WrongAudience2297=== RUN TestValidateToken_Expired2298=== PAUSE TestValidateToken_Expired2299=== RUN TestValidateToken_BoundClaimsMismatch2300=== PAUSE TestValidateToken_BoundClaimsMismatch2301=== RUN TestValidateToken_BoundSubjectMismatch2302=== PAUSE TestValidateToken_BoundSubjectMismatch2303=== RUN TestValidateToken_MultipleProviders2304=== PAUSE TestValidateToken_MultipleProviders2305=== RUN TestValidateToken_NoMatchingProvider2306=== PAUSE TestValidateToken_NoMatchingProvider2307=== RUN TestValidateToken_KubernetesServiceAccount2308=== PAUSE TestValidateToken_KubernetesServiceAccount2309=== RUN TestNewValidator_KubernetesRequiresCA2310=== PAUSE TestNewValidator_KubernetesRequiresCA2311=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2312=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2313=== RUN TestScopes_LegacyProviderDefaultsToWrite2314=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2315=== RUN TestScopes_Rules2316=== PAUSE TestScopes_Rules2317=== RUN TestScopes_ConfigValidation2318=== PAUSE TestScopes_ConfigValidation2319=== CONT TestGlobMatch2320=== CONT TestScopes_LegacyProviderDefaultsToWrite2321=== CONT TestScopes_ConfigValidation2322=== RUN TestGlobMatch/foo_foo2323=== PAUSE TestGlobMatch/foo_foo2324=== CONT TestValidateToken_MultipleProviders2325=== CONT TestValidateToken_BoundSubjectMismatch2326=== CONT TestValidateToken_BoundClaimsMismatch2327=== CONT TestValidateToken_Expired2328=== CONT TestValidateToken_WrongAudience2329=== CONT TestValidateToken_ValidToken2330=== CONT TestAudienceForIssuer2331=== CONT TestScopes_Rules2332=== CONT TestNewValidator_KubernetesRequiresCA2333=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2334=== CONT TestValidateToken_KubernetesServiceAccount2335=== CONT TestValidateToken_NoMatchingProvider2336=== RUN TestGlobMatch/foo_bar2337=== PAUSE TestGlobMatch/foo_bar2338=== RUN TestGlobMatch/*_2339=== PAUSE TestGlobMatch/*_2340=== RUN TestGlobMatch/*_anything2341=== PAUSE TestGlobMatch/*_anything2342=== RUN TestGlobMatch/foo*_foo2343=== PAUSE TestGlobMatch/foo*_foo2344=== RUN TestGlobMatch/foo*_foobar2345=== PAUSE TestGlobMatch/foo*_foobar2346=== RUN TestGlobMatch/foo*_bar2347=== PAUSE TestGlobMatch/foo*_bar2348=== RUN TestGlobMatch/*bar_bar2349=== PAUSE TestGlobMatch/*bar_bar2350=== RUN TestGlobMatch/*bar_foobar2351=== PAUSE TestGlobMatch/*bar_foobar2352=== RUN TestGlobMatch/*bar_foo2353=== PAUSE TestGlobMatch/*bar_foo2354=== RUN TestGlobMatch/foo*bar_foobar2355=== PAUSE TestGlobMatch/foo*bar_foobar2356=== RUN TestGlobMatch/foo*bar_foo123bar2357=== PAUSE TestGlobMatch/foo*bar_foo123bar2358=== RUN TestGlobMatch/foo*bar_foobarbaz2359=== PAUSE TestGlobMatch/foo*bar_foobarbaz2360=== RUN TestGlobMatch/*/*_foo/bar2361=== PAUSE TestGlobMatch/*/*_foo/bar2362=== RUN TestGlobMatch/*/*_foo2363=== PAUSE TestGlobMatch/*/*_foo2364=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2365=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2366=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02367=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02368=== RUN TestGlobMatch/refs/*/main_refs/heads/main2369=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2370=== RUN TestGlobMatch/fo?_foo2371=== PAUSE TestGlobMatch/fo?_foo2372=== RUN TestGlobMatch/fo?_fo2373=== PAUSE TestGlobMatch/fo?_fo2374=== RUN TestGlobMatch/fo?_fooo2375=== PAUSE TestGlobMatch/fo?_fooo2376--- PASS: TestAudienceForIssuer (0.00s)2377=== 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=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2387=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2388=== CONT TestGlobMatch/?oo_boo2389=== CONT TestGlobMatch/fo?_fooo2390=== CONT TestGlobMatch/*_2391=== CONT TestGlobMatch/foo*bar_foo123bar2392=== CONT TestGlobMatch/foo_bar2393=== CONT TestGlobMatch/?oo_foo2394=== CONT TestGlobMatch/foo*bar_foobar2395=== CONT TestGlobMatch/*bar_foo2396=== CONT TestGlobMatch/*bar_foobar2397=== CONT TestGlobMatch/*bar_bar2398=== CONT TestGlobMatch/foo*_bar2399=== CONT TestGlobMatch/*/*_foo24002026/09/18 13:10:17 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC1232401=== CONT TestGlobMatch/foo*_foobar2402=== CONT TestGlobMatch/foo*_foo2403=== CONT TestGlobMatch/*_anything24042026/09/18 13:10:17 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:37787/oidc24052026/09/18 13:10:17 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:39885/oidc2406=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02407=== CONT TestGlobMatch/fo?_fo24082026/09/18 13:10:17 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:33279/oidc2409--- PASS: TestScopes_ConfigValidation (0.00s)24102026/09/18 13:10:17 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:35027/oidc2411=== CONT TestGlobMatch/fo?_foo2412=== CONT TestGlobMatch/refs/*/main_refs/heads/main2413=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2414=== CONT TestGlobMatch/*/*_foo/bar24152026/09/18 13:10:17 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:35115/oidc2416=== CONT TestGlobMatch/foo*bar_foobarbaz24172026/09/18 13:10:17 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:34751/oidc24182026/09/18 13:10:17 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:39609/oidc2419--- PASS: TestGlobMatch (0.00s)2420 --- PASS: TestGlobMatch/foo_foo (0.00s)2421 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2422 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2423 --- PASS: TestGlobMatch/?oo_boo (0.00s)2424 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2425 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2426 --- PASS: TestGlobMatch/foo_bar (0.00s)2427 --- PASS: TestGlobMatch/*_ (0.00s)2428 --- PASS: TestGlobMatch/?oo_foo (0.00s)2429 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2430 --- PASS: TestGlobMatch/*bar_foo (0.00s)2431 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2432 --- PASS: TestGlobMatch/foo*_bar (0.00s)2433 --- PASS: TestGlobMatch/*/*_foo (0.00s)2434 --- PASS: TestGlobMatch/*bar_bar (0.00s)2435 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2436 --- PASS: TestGlobMatch/foo*_foo (0.00s)2437 --- PASS: TestGlobMatch/*_anything (0.00s)2438 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2439 --- PASS: TestGlobMatch/fo?_foo (0.00s)2440 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2441 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2442 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2443 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2444 --- PASS: TestGlobMatch/fo?_fo (0.00s)24452026/09/18 13:10:17 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:42661/oidc24462026/09/18 13:10:17 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:33569/oidc24472026/09/18 13:10:17 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:35035/oidc2448--- PASS: TestValidateToken_BoundClaimsMismatch (0.02s)2449--- PASS: TestValidateToken_Expired (0.02s)2450--- PASS: TestValidateToken_NoMatchingProvider (0.02s)2451--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.02s)2452--- PASS: TestValidateToken_BoundSubjectMismatch (0.02s)2453--- PASS: TestValidateToken_ValidToken (0.02s)2454--- PASS: TestValidateToken_WrongAudience (0.02s)2455--- PASS: TestValidateToken_MultipleProviders (0.02s)24562026/09/18 13:10:17 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:387632457--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.02s)2458--- PASS: TestValidateToken_KubernetesServiceAccount (0.02s)24592026/09/18 13:10:17 http: TLS handshake error from 127.0.0.1:59284: remote error: tls: bad certificate2460--- PASS: TestNewValidator_KubernetesRequiresCA (0.02s)2461--- PASS: TestScopes_Rules (0.02s)2462PASS2463Running hook tests...2464=== RUN TestSendPathsEmpty2465=== PAUSE TestSendPathsEmpty2466=== RUN TestQueueEnqueueAndFetch2467=== PAUSE TestQueueEnqueueAndFetch2468=== RUN TestQueueDeduplication2469=== PAUSE TestQueueDeduplication2470=== RUN TestQueueRemove2471=== PAUSE TestQueueRemove2472=== RUN TestQueueFetchBatchLimit2473=== PAUSE TestQueueFetchBatchLimit2474=== RUN TestQueueRetryMovesToBack2475=== PAUSE TestQueueRetryMovesToBack2476=== RUN TestQueueFetchRemoveLifecycle2477=== PAUSE TestQueueFetchRemoveLifecycle2478=== RUN TestQueueConcurrentWriters2479=== PAUSE TestQueueConcurrentWriters2480=== RUN TestQueueRemoveLargeClosure2481=== PAUSE TestQueueRemoveLargeClosure2482=== RUN TestServerClientIntegration2483=== PAUSE TestServerClientIntegration2484=== RUN TestServerQueueError2485=== PAUSE TestServerQueueError2486=== RUN TestGetListenerSocketActivation2487 server_test.go:210: === RUN TestGetListenerSocketActivation2488 --- PASS: TestGetListenerSocketActivation (0.00s)2489 PASS2490 2491--- PASS: TestGetListenerSocketActivation (0.01s)2492=== RUN TestDrainIsolatesPoisonPath2493=== PAUSE TestDrainIsolatesPoisonPath2494=== RUN TestRunNotBlockedByPoisonHead2495=== PAUSE TestRunNotBlockedByPoisonHead2496=== RUN TestDrainGivesUpWhenServerDown2497=== PAUSE TestDrainGivesUpWhenServerDown2498=== RUN TestFailedPathPrunedByLaterClosure2499=== PAUSE TestFailedPathPrunedByLaterClosure2500=== RUN TestWorkerUploadsAndRemoves2501=== PAUSE TestWorkerUploadsAndRemoves2502=== RUN TestWorkerSkipsGCdPaths2503=== PAUSE TestWorkerSkipsGCdPaths2504=== RUN TestWorkerPrunesClosureDeps2505=== PAUSE TestWorkerPrunesClosureDeps2506=== RUN TestDrainTimeout2507=== PAUSE TestDrainTimeout2508=== CONT TestSendPathsEmpty2509=== CONT TestServerQueueError2510=== CONT TestQueueDeduplication2511--- PASS: TestSendPathsEmpty (0.00s)2512=== CONT TestQueueRetryMovesToBack2513=== CONT TestQueueFetchBatchLimit2514=== CONT TestServerClientIntegration2515=== CONT TestQueueRemoveLargeClosure2516=== CONT TestQueueConcurrentWriters2517=== CONT TestQueueEnqueueAndFetch2518=== CONT TestQueueFetchRemoveLifecycle2519=== CONT TestQueueRemove2520=== CONT TestWorkerUploadsAndRemoves2521=== CONT TestDrainGivesUpWhenServerDown2522=== CONT TestDrainTimeout25232026/09/18 13:10:17 ERROR Failed to queue paths error="permission denied" count=12524=== CONT TestWorkerPrunesClosureDeps2525=== CONT TestFailedPathPrunedByLaterClosure2526=== CONT TestWorkerSkipsGCdPaths2527=== CONT TestRunNotBlockedByPoisonHead2528=== CONT TestDrainIsolatesPoisonPath2529--- PASS: TestServerClientIntegration (0.00s)2530--- PASS: TestServerQueueError (0.00s)25312026/09/18 13:10:17 INFO Upload queue status pending=225322026/09/18 13:10:17 INFO Uploading batch count=125332026/09/18 13:10:17 INFO Upload queue status pending=225342026/09/18 13:10:17 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerSkipsGCdPaths1692399141/002/nonexistent25352026/09/18 13:10:17 INFO Uploading batch count=425362026/09/18 13:10:17 ERROR Upload failed error="upload failed" count=425372026/09/18 13:10:17 INFO Uploading batch count=125382026/09/18 13:10:17 ERROR Upload failed error="upload failed" count=125392026/09/18 13:10:17 INFO Upload queue status pending=225402026/09/18 13:10:17 INFO Uploading batch count=22541--- PASS: TestQueueDeduplication (0.02s)25422026/09/18 13:10:17 INFO Uploading batch count=22543--- PASS: TestQueueEnqueueAndFetch (0.02s)25442026/09/18 13:10:17 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainIsolatesPoisonPath85984274/002/bbb25452026/09/18 13:10:17 INFO Uploading batch count=125462026/09/18 13:10:17 INFO Uploading batch count=225472026/09/18 13:10:17 ERROR Upload failed error="upload failed" count=225482026/09/18 13:10:17 INFO Uploading batch count=125492026/09/18 13:10:17 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3098876261/002/a25502026/09/18 13:10:17 INFO Upload queue status pending=32551--- PASS: TestQueueFetchRemoveLifecycle (0.02s)25522026/09/18 13:10:17 INFO Uploading batch count=125532026/09/18 13:10:17 ERROR Upload failed error="upload failed" count=12554--- PASS: TestQueueRetryMovesToBack (0.02s)25552026/09/18 13:10:17 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3098876261/002/b2556--- PASS: TestQueueRemove (0.02s)2557--- PASS: TestQueueFetchBatchLimit (0.02s)25582026/09/18 13:10:17 INFO Uploading batch count=125592026/09/18 13:10:17 INFO Uploading batch count=225602026/09/18 13:10:17 ERROR Upload failed error="upload failed" count=225612026/09/18 13:10:17 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3098876261/002/c25622026/09/18 13:10:17 INFO Uploading batch count=125632026/09/18 13:10:17 ERROR Upload failed error="upload failed" count=125642026/09/18 13:10:17 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3098876261/002/d25652026/09/18 13:10:17 INFO Uploading batch count=125662026/09/18 13:10:17 ERROR Upload failed error="upload failed" count=125672026/09/18 13:10:17 INFO Uploading batch count=225682026/09/18 13:10:17 ERROR Upload failed error="upload failed" count=225692026/09/18 13:10:17 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3098876261/002/e25702026/09/18 13:10:17 INFO Uploading batch count=125712026/09/18 13:10:17 ERROR Upload failed error="upload failed" count=125722026/09/18 13:10:17 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3098876261/002/f25732026/09/18 13:10:17 ERROR Drain finished with paths left in queue remaining=125742026/09/18 13:10:17 ERROR Drain finished with paths left in queue remaining=102575--- PASS: TestFailedPathPrunedByLaterClosure (0.02s)2576--- PASS: TestDrainIsolatesPoisonPath (0.02s)2577--- PASS: TestDrainGivesUpWhenServerDown (0.03s)2578--- PASS: TestWorkerPrunesClosureDeps (0.04s)2579--- PASS: TestWorkerSkipsGCdPaths (0.04s)2580--- PASS: TestWorkerUploadsAndRemoves (0.04s)2581--- PASS: TestQueueRemoveLargeClosure (0.08s)25822026/09/18 13:10:17 ERROR Upload failed error="context deadline exceeded" count=225832026/09/18 13:10:17 ERROR Drain finished with paths left in queue remaining=42584--- PASS: TestDrainTimeout (0.22s)2585--- PASS: TestQueueConcurrentWriters (0.28s)25862026/09/18 13:10:18 INFO Uploading batch count=125872026/09/18 13:10:18 INFO Uploading batch count=125882026/09/18 13:10:18 INFO Uploading batch count=125892026/09/18 13:10:18 ERROR Upload failed error="upload failed" count=125902026/09/18 13:10:18 INFO Uploading batch count=125912026/09/18 13:10:18 ERROR Upload failed error="upload failed" count=125922026/09/18 13:10:18 INFO Uploading batch count=125932026/09/18 13:10:18 ERROR Upload failed error="upload failed" count=125942026/09/18 13:10:18 INFO Uploading batch count=125952026/09/18 13:10:18 ERROR Upload failed error="upload failed" count=125962026/09/18 13:10:18 ERROR Drain finished with paths left in queue remaining=12597--- PASS: TestRunNotBlockedByPoisonHead (1.04s)2598PASS