niks3-go-unit-tests
checks.aarch64-linux.go-unit-tests
· build #203
· raw
1tribuchet: building on eliza2Running client tests...3=== RUN TestDoServerRequestAttachesToken4=== PAUSE TestDoServerRequestAttachesToken5=== RUN TestCaseHackSuffix6=== PAUSE TestCaseHackSuffix7=== RUN TestFilterOversizedClosures8=== PAUSE TestFilterOversizedClosures9=== RUN TestPartSizeForNAR10=== PAUSE TestPartSizeForNAR11=== RUN TestUploadMultipart_SupersededByPeer12=== PAUSE TestUploadMultipart_SupersededByPeer13=== RUN TestDumpPathCaseHackMatchesNix14--- PASS: TestDumpPathCaseHackMatchesNix (0.03s)15=== RUN TestDumpPathCaseHackCollision16--- PASS: TestDumpPathCaseHackCollision (0.00s)17=== RUN TestDumpPathMatchesNix18=== PAUSE TestDumpPathMatchesNix19=== RUN TestDumpPathSingleFile20=== PAUSE TestDumpPathSingleFile21=== RUN TestDumpPathWriterError22=== PAUSE TestDumpPathWriterError23=== RUN TestEncodeNixBase3224=== PAUSE TestEncodeNixBase3225=== RUN TestEncodeNixBase32WithRealHash26=== PAUSE TestEncodeNixBase32WithRealHash27=== RUN TestConvertHashToNix3228=== PAUSE TestConvertHashToNix3229=== RUN TestGetStorePathHash30=== PAUSE TestGetStorePathHash31=== RUN TestPathInfoHashCompatibility32=== PAUSE TestPathInfoHashCompatibility33=== RUN TestParsePathInfoJSON34=== PAUSE TestParsePathInfoJSON35=== RUN TestParsePathInfoJSONMultiplePaths36=== PAUSE TestParsePathInfoJSONMultiplePaths37=== RUN TestPathInfoCACompatibility38=== PAUSE TestPathInfoCACompatibility39=== RUN TestRateLimiterFeedback40=== PAUSE TestRateLimiterFeedback41=== RUN TestRateLimiterFeedback_400DoesNotCountAsSuccess42=== PAUSE TestRateLimiterFeedback_400DoesNotCountAsSuccess43=== RUN TestResolveStorePath44=== PAUSE TestResolveStorePath45=== RUN TestDoWithRetry_BodyReplayedViaGetBody46=== PAUSE TestDoWithRetry_BodyReplayedViaGetBody47=== RUN TestShellSplit48=== PAUSE TestShellSplit49=== RUN TestShellSplitErrors50=== PAUSE TestShellSplitErrors51=== RUN TestStreamPushReportsEveryPath52=== PAUSE TestStreamPushReportsEveryPath53=== RUN TestStreamPushBatchesUnderLoad54=== PAUSE TestStreamPushBatchesUnderLoad55=== RUN TestStreamPushIsolatesFailures56=== PAUSE TestStreamPushIsolatesFailures57=== RUN TestStreamPushGivesUpOnDeadServer58=== PAUSE TestStreamPushGivesUpOnDeadServer59=== RUN TestStreamPushRequestLine60=== PAUSE TestStreamPushRequestLine61=== RUN TestSetClientTLS62=== PAUSE TestSetClientTLS63=== RUN TestSetClientTLSDoesNotMutateDefaultTransport64=== PAUSE TestSetClientTLSDoesNotMutateDefaultTransport65=== RUN TestSetClientTLSErrors66=== PAUSE TestSetClientTLSErrors67=== RUN TestStaticToken68=== PAUSE TestStaticToken69=== RUN TestFileTokenReadsAndCaches70=== PAUSE TestFileTokenReadsAndCaches71=== RUN TestFileTokenMissing72=== PAUSE TestFileTokenMissing73=== RUN TestFileTokenEmpty74=== PAUSE TestFileTokenEmpty75=== RUN TestScriptTokenNoExpiryRerunsEveryCall76=== PAUSE TestScriptTokenNoExpiryRerunsEveryCall77=== RUN TestScriptTokenCachesUntilRefresh78=== PAUSE TestScriptTokenCachesUntilRefresh79=== RUN TestScriptTokenEmptyToken80=== PAUSE TestScriptTokenEmptyToken81=== RUN TestScriptTokenBadJSON82=== PAUSE TestScriptTokenBadJSON83=== RUN TestScriptTokenScriptFails84=== PAUSE TestScriptTokenScriptFails85=== RUN TestScriptTokenEmptyCommand86=== PAUSE TestScriptTokenEmptyCommand87=== CONT TestDoServerRequestAttachesToken88=== CONT TestSetClientTLS89=== CONT TestParsePathInfoJSONMultiplePaths90=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths91=== CONT TestScriptTokenNoExpiryRerunsEveryCall92=== CONT TestStreamPushRequestLine93=== CONT TestScriptTokenEmptyCommand94--- PASS: TestScriptTokenEmptyCommand (0.00s)95=== CONT TestRateLimiterFeedback96=== RUN TestRateLimiterFeedback/429_enables_limiter97=== PAUSE TestRateLimiterFeedback/429_enables_limiter98=== RUN TestRateLimiterFeedback/503_enables_limiter99=== PAUSE TestRateLimiterFeedback/503_enables_limiter100=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter101=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter102=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter103=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter104=== CONT TestDumpPathMatchesNix105=== CONT TestStreamPushGivesUpOnDeadServer106=== CONT TestScriptTokenScriptFails107=== CONT TestStreamPushIsolatesFailures108=== CONT TestScriptTokenBadJSON109=== CONT TestStreamPushBatchesUnderLoad1102026/09/13 15:15:59 ERROR Upload failed error="connection refused" count=20111=== CONT TestScriptTokenEmptyToken1122026/09/13 15:15:59 ERROR Server seems unavailable, giving up on batch untried=17113=== CONT TestStreamPushReportsEveryPath1142026/09/13 15:15:59 ERROR Upload failed error="stale build claim" count=1115=== CONT TestScriptTokenCachesUntilRefresh1162026/09/13 15:15:59 ERROR Upload failed error="bad path" count=3117=== CONT TestShellSplitErrors118--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)119=== CONT TestPathInfoCACompatibility120=== RUN TestPathInfoCACompatibility/null_ca_field121=== CONT TestGetStorePathHash122=== PAUSE TestPathInfoCACompatibility/null_ca_field123--- PASS: TestStreamPushReportsEveryPath (0.00s)124--- PASS: TestShellSplitErrors (0.00s)125=== CONT TestFilterOversizedClosures126=== CONT TestShellSplit127=== CONT TestFileTokenEmpty128=== RUN TestFilterOversizedClosures/no_limit_keeps_everything129=== CONT TestDoWithRetry_BodyReplayedViaGetBody130=== CONT TestFileTokenMissing131=== CONT TestResolveStorePath132=== CONT TestUploadMultipart_SupersededByPeer133=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess134=== CONT TestDumpPathSingleFile135=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths136=== CONT TestParsePathInfoJSON137=== CONT TestFileTokenReadsAndCaches138=== CONT TestPathInfoHashCompatibility139--- PASS: TestStreamPushIsolatesFailures (0.00s)140--- PASS: TestStreamPushRequestLine (0.00s)141--- PASS: TestShellSplit (0.00s)142=== RUN TestGetStorePathHash/valid_store_path143=== PAUSE TestGetStorePathHash/valid_store_path144=== RUN TestGetStorePathHash/basename_without_hyphen_should_error145=== RUN TestPathInfoCACompatibility/old_string_format_-_text146=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text147=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive148=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive149=== RUN TestPathInfoCACompatibility/new_structured_format_-_text150=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text151=== CONT TestPartSizeForNAR152=== RUN TestPartSizeForNAR/zero_stays_at_minimum153=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error154=== CONT TestEncodeNixBase32WithRealHash155=== CONT TestSetClientTLSErrors156=== CONT TestConvertHashToNix32157=== RUN TestConvertHashToNix32/SRI_format_to_Nix32158=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32159=== RUN TestConvertHashToNix32/already_Nix32_format160=== PAUSE TestConvertHashToNix32/already_Nix32_format161=== RUN TestConvertHashToNix32/invalid_format162=== PAUSE TestConvertHashToNix32/invalid_format163=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method164=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method165=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum166=== CONT TestStaticToken167=== RUN TestUploadMultipart_SupersededByPeer/exists168=== PAUSE TestUploadMultipart_SupersededByPeer/exists169=== CONT TestCaseHackSuffix170=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)171--- PASS: TestScriptTokenScriptFails (0.00s)172=== CONT TestSetClientTLSDoesNotMutateDefaultTransport173=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything174=== CONT TestEncodeNixBase32175=== RUN TestPartSizeForNAR/small_stays_at_minimum176=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error177=== RUN TestUploadMultipart_SupersededByPeer/missing178=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths179=== RUN TestParsePathInfoJSON/Nix_format180=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)181--- PASS: TestFileTokenEmpty (0.00s)182=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped183=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon184=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter185=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths186=== PAUSE TestUploadMultipart_SupersededByPeer/missing1872026/09/13 15:15:59 WARN Rate limiter enabled after throttle name=server-test rate=5188=== PAUSE TestPartSizeForNAR/small_stays_at_minimum189=== PAUSE TestParsePathInfoJSON/Nix_format190=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error191=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter192=== CONT TestDumpPathWriterError193--- PASS: TestEncodeNixBase32WithRealHash (0.00s)194=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon1952026/09/13 15:15:59 WARN Rate limiter enabled after throttle name=server-test rate=5196=== CONT TestRateLimiterFeedback/429_enables_limiter197=== RUN TestSetClientTLSErrors/missing_cert_file1982026/09/13 15:15:59 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:37297199=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped200=== RUN TestEncodeNixBase32/test_string_hash201=== CONT TestRateLimiterFeedback/503_enables_limiter202=== PAUSE TestEncodeNixBase32/test_string_hash203=== RUN TestEncodeNixBase32/empty_input204=== RUN TestFilterOversizedClosures/all_closures_skipped205--- PASS: TestResolveStorePath (0.01s)206=== PAUSE TestFilterOversizedClosures/all_closures_skipped207=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum208=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI209=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error210=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error211=== CONT TestConvertHashToNix32/invalid_format2122026/09/13 15:15:59 WARN Rate limiter enabled after throttle name=server-test rate=5213=== RUN TestSetClientTLS/rejects_connection_without_client_cert214=== PAUSE TestSetClientTLSErrors/missing_cert_file2152026/09/13 15:15:59 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:46361216=== PAUSE TestEncodeNixBase32/empty_input217=== CONT TestConvertHashToNix32/already_Nix32_format218=== CONT TestConvertHashToNix32/SRI_format_to_Nix322192026/09/13 15:15:59 WARN Rate limiter enabled after throttle name=server-test rate=5220=== CONT TestPathInfoCACompatibility/null_ca_field2212026/09/13 15:15:59 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:36401222=== RUN TestParsePathInfoJSON/Lix_format2232026/09/13 15:15:59 WARN Rate limiter backed off name=server-test rate=5224--- PASS: TestDoServerRequestAttachesToken (0.01s)2252026/09/13 15:15:59 WARN Rate limiter backed off name=server-test rate=5226=== CONT TestPathInfoCACompatibility/new_structured_format_-_text227=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum2282026/09/13 15:15:59 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:37297229=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI230=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method2312026/09/13 15:15:59 WARN Rate limiter backed off name=server-test rate=5232=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive233=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped234=== CONT TestGetStorePathHash/valid_store_path2352026/09/13 15:15:59 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=2000236=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert237=== CONT TestEncodeNixBase32/empty_input238=== RUN TestSetClientTLSErrors/missing_key_file239=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths240=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths241=== CONT TestPathInfoCACompatibility/old_string_format_-_text242=== CONT TestUploadMultipart_SupersededByPeer/exists243=== CONT TestUploadMultipart_SupersededByPeer/missing244=== PAUSE TestParsePathInfoJSON/Lix_format245--- PASS: TestScriptTokenBadJSON (0.01s)246=== CONT TestFilterOversizedClosures/no_limit_keeps_everything247=== RUN TestParsePathInfoJSON/empty_input248=== CONT TestFilterOversizedClosures/all_closures_skipped249=== PAUSE TestParsePathInfoJSON/empty_input2502026/09/13 15:15:59 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=50251=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts252=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512253=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error254=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error255=== CONT TestGetStorePathHash/basename_without_hyphen_should_error256=== CONT TestEncodeNixBase32/test_string_hash257=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA258=== PAUSE TestSetClientTLSErrors/missing_key_file259--- PASS: TestFileTokenReadsAndCaches (0.00s)260--- PASS: TestScriptTokenEmptyToken (0.01s)261--- PASS: TestFileTokenMissing (0.00s)262--- PASS: TestStaticToken (0.00s)263--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.03s)264--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.02s)265=== RUN TestParsePathInfoJSON/whitespace_only266=== RUN TestSetClientTLSErrors/missing_ca_file267=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512268=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)269=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon270=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts271=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512272--- PASS: TestConvertHashToNix32 (0.00s)273 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)274 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)275 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)276--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.02s)277=== PAUSE TestSetClientTLSErrors/missing_ca_file278=== PAUSE TestParsePathInfoJSON/whitespace_only279=== RUN TestSetClientTLSErrors/invalid_ca_file280=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI281=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA282=== RUN TestPartSizeForNAR/1_TiB283--- PASS: TestScriptTokenCachesUntilRefresh (0.03s)284--- PASS: TestRateLimiterFeedback (0.00s)285 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.01s)286 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.01s)287 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.01s)288 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.01s)289=== RUN TestParsePathInfoJSON/invalid_JSON290=== RUN TestSetClientTLS/preserves_debug_logging_transport291=== PAUSE TestPartSizeForNAR/1_TiB292=== PAUSE TestSetClientTLS/preserves_debug_logging_transport293=== PAUSE TestSetClientTLSErrors/invalid_ca_file294=== CONT TestSetClientTLSErrors/missing_cert_file295--- PASS: TestEncodeNixBase32 (0.02s)296 --- PASS: TestEncodeNixBase32/empty_input (0.00s)297 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)298--- PASS: TestPathInfoHashCompatibility (0.04s)299 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)300 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)301 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)302 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)303--- PASS: TestGetStorePathHash (0.02s)304 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)305 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)306 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)307 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)308--- PASS: TestParsePathInfoJSONMultiplePaths (0.02s)309 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)310 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)311--- PASS: TestFilterOversizedClosures (0.02s)312 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)313 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)314 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)315--- PASS: TestPathInfoCACompatibility (0.00s)316 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)317 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)318 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)319 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)320 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)321--- PASS: TestDumpPathSingleFile (0.04s)322=== PAUSE TestParsePathInfoJSON/invalid_JSON323=== CONT TestParsePathInfoJSON/Nix_format324=== RUN TestPartSizeForNAR/5_TiB_S3_max_object325=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object326=== RUN TestPartSizeForNAR/capped_at_5_GiB327=== PAUSE TestPartSizeForNAR/capped_at_5_GiB328=== CONT TestPartSizeForNAR/zero_stays_at_minimum329=== CONT TestParsePathInfoJSON/invalid_JSON330=== CONT TestParsePathInfoJSON/whitespace_only331=== CONT TestParsePathInfoJSON/empty_input332=== CONT TestParsePathInfoJSON/Lix_format333--- PASS: TestParsePathInfoJSON (0.04s)334 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)335 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)336 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)337 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)338 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)339=== CONT TestSetClientTLS/preserves_debug_logging_transport340=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA341=== CONT TestSetClientTLS/rejects_connection_without_client_cert342=== CONT TestSetClientTLSErrors/missing_ca_file343=== CONT TestPartSizeForNAR/1_TiB344=== CONT TestPartSizeForNAR/5_TiB_S3_max_object345=== CONT TestSetClientTLSErrors/missing_key_file346=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts347=== CONT TestPartSizeForNAR/small_stays_at_minimum348=== CONT TestSetClientTLSErrors/invalid_ca_file349=== CONT TestPartSizeForNAR/capped_at_5_GiB350=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum351--- PASS: TestUploadMultipart_SupersededByPeer (0.01s)352 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.02s)353 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.02s)354--- PASS: TestPartSizeForNAR (0.04s)355 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)356 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)357 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)358 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)359 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)360 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)361 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)362--- PASS: TestCaseHackSuffix (0.05s)363--- PASS: TestSetClientTLSErrors (0.04s)364 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)365 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)366 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)367 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)3682026/09/13 15:15:59 http: TLS handshake error from 127.0.0.1:33152: remote error: tls: bad certificate369--- PASS: TestSetClientTLS (0.05s)370 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.01s)371 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.01s)372 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.01s)373--- PASS: TestDumpPathWriterError (0.06s)374--- PASS: TestStreamPushBatchesUnderLoad (0.10s)375--- PASS: TestDumpPathMatchesNix (0.12s)376--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.01s)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/postgres2573516888/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/postgres2573516888/data -l logfile start405406/build/postgres2573516888:5432 - no response4072026-09-13 15:16:01.474 UTC [127] LOG: starting PostgreSQL 18.6 on aarch64-unknown-linux-gnu, compiled by clang version 21.1.8, 64-bit4082026-09-13 15:16:01.474 UTC [127] LOG: listening on Unix socket "/build/postgres2573516888/.s.PGSQL.5432"4092026-09-13 15:16:01.480 UTC [134] LOG: database system was shut down at 2026-09-13 15:16:01 UTC4102026-09-13 15:16:01.484 UTC [127] LOG: database system is ready to accept connections411/build/postgres2573516888: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 TestClientCADerivations451=== PAUSE TestClientCADerivations452=== RUN TestClientErrorHandling453=== PAUSE TestClientErrorHandling454=== RUN TestClientIntegration455=== PAUSE TestClientIntegration456=== RUN TestClientMultipleUploads457=== PAUSE TestClientMultipleUploads458=== RUN TestClientWithDependencies459=== PAUSE TestClientWithDependencies460=== RUN TestPinProtectsFromGC461=== PAUSE TestPinProtectsFromGC462=== RUN TestResolveDBConnectionString463=== PAUSE TestResolveDBConnectionString464=== RUN TestGCAdvisoryLockBlocksConcurrentRun4652026-09-13 15:16:03.519 UTC [535] ERROR: relation "goose_db_version" does not exist at character 364662026-09-13 15:16:03.519 UTC [535] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC4672026/09/13 15:16:03 OK 20241026095416_initial_model.sql (15.02ms)4682026/09/13 15:16:03 OK 20251210153512_drop_unused_gin_index.sql (2.27ms)4692026/09/13 15:16:03 OK 20251218171726_add_pins.sql (3.31ms)4702026/09/13 15:16:03 OK 20260628120000_add_object_size_and_stats.sql (3.62ms)4712026/09/13 15:16:03 OK 20260905000000_add_claims.sql (3.7ms)4722026/09/13 15:16:03 goose: successfully migrated database to version: 202609050000004732026/09/13 15:16:03 OK 1_commit_pending_closure.sql (2.06ms)4742026/09/13 15:16:03 OK 2_object_stats_trigger.sql (888.77µs)4752026/09/13 15:16:03 goose: up to current file version: 2476--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.58s)477=== RUN TestGCBugBareHashReferences478=== PAUSE TestGCBugBareHashReferences479=== RUN TestGCMetrics480=== PAUSE TestGCMetrics481=== RUN TestGCTaskStore_StartNew482=== PAUSE TestGCTaskStore_StartNew483=== RUN TestGCTaskStore_DeduplicateSameParams484=== PAUSE TestGCTaskStore_DeduplicateSameParams485=== RUN TestGCTaskStore_ConflictDifferentParams486=== PAUSE TestGCTaskStore_ConflictDifferentParams487=== RUN TestGCTaskStore_GetEmpty488=== PAUSE TestGCTaskStore_GetEmpty489=== RUN TestGCTaskStore_GetReturnsLatest490=== PAUSE TestGCTaskStore_GetReturnsLatest491=== RUN TestGCTaskStore_CompletedAllowsNewTask492=== PAUSE TestGCTaskStore_CompletedAllowsNewTask493=== RUN TestGCTaskStore_PhaseUpdates494=== PAUSE TestGCTaskStore_PhaseUpdates495=== RUN TestGCTaskStore_Fail496=== PAUSE TestGCTaskStore_Fail497=== RUN TestGracefulShutdownDrainsInflight498=== PAUSE TestGracefulShutdownDrainsInflight499=== RUN TestService_healthCheckHandler500=== PAUSE TestService_healthCheckHandler501=== RUN TestService_readinessHandler502=== PAUSE TestService_readinessHandler503=== RUN TestGenerateLandingPage504=== PAUSE TestGenerateLandingPage505=== RUN TestCacheConfigHandlerMaxNarSize506=== PAUSE TestCacheConfigHandlerMaxNarSize507=== RUN TestCreatePendingClosureRejectsOversizedNAR508=== PAUSE TestCreatePendingClosureRejectsOversizedNAR509=== RUN TestNARDeduplicationMetadataUploadBug510=== PAUSE TestNARDeduplicationMetadataUploadBug511=== RUN TestMetricsInventory512=== PAUSE TestMetricsInventory513=== RUN TestService_NativeMTLS514=== PAUSE TestService_NativeMTLS515=== RUN TestServerTLSConfig516=== PAUSE TestServerTLSConfig517=== RUN TestMultipartCleanup518=== PAUSE TestMultipartCleanup519=== RUN TestObjectStatsTrigger520=== PAUSE TestObjectStatsTrigger521=== RUN TestOrphanedObjectsGC522=== PAUSE TestOrphanedObjectsGC523=== RUN TestOrphanedObjectsGCStressTest524=== PAUSE TestOrphanedObjectsGCStressTest525=== RUN TestResurrectedObjectNotDeleted526=== PAUSE TestResurrectedObjectNotDeleted527=== RUN TestParseSingleRange528=== PAUSE TestParseSingleRange529=== RUN TestIsValidCachePath530=== PAUSE TestIsValidCachePath531=== RUN TestReadProxyNarinfo532=== PAUSE TestReadProxyNarinfo533=== RUN TestReadProxyNarinfoAlreadyDecompressed534=== PAUSE TestReadProxyNarinfoAlreadyDecompressed535=== RUN TestReadProxyNarStreaming536=== PAUSE TestReadProxyNarStreaming537=== RUN TestReadProxy404538=== PAUSE TestReadProxy404539=== RUN TestReadProxyInvalidPath540=== PAUSE TestReadProxyInvalidPath541=== RUN TestReadProxyHead542=== PAUSE TestReadProxyHead543=== RUN TestReadProxyConditionalGet544=== PAUSE TestReadProxyConditionalGet545=== RUN TestReadProxyRootRedirectsToIndexHTML546=== PAUSE TestReadProxyRootRedirectsToIndexHTML547=== RUN TestReadProxyDisabled548=== PAUSE TestReadProxyDisabled549=== RUN TestReadRedirectNar550=== PAUSE TestReadRedirectNar551=== RUN TestReadRedirectKeepsNarinfoProxied552=== PAUSE TestReadRedirectKeepsNarinfoProxied553=== RUN TestReadProxyRangeRequest554=== PAUSE TestReadProxyRangeRequest555=== RUN TestReadRedirectUsesPublicS3URL556=== PAUSE TestReadRedirectUsesPublicS3URL557=== RUN TestRedundantMultipartUpload558=== PAUSE TestRedundantMultipartUpload559=== RUN TestCompleteMultipartUpload_ErrorButObjectExists560=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists561=== RUN TestCompletedNarNotReofferedAcrossClosures562=== PAUSE TestCompletedNarNotReofferedAcrossClosures563=== RUN TestPresignedUploadRegisteredBeforeCommit564=== PAUSE TestPresignedUploadRegisteredBeforeCommit565=== RUN TestService_Rustfstest566=== PAUSE TestService_Rustfstest567=== RUN TestParseSize568=== PAUSE TestParseSize569=== RUN TestSkippedUploadsHandler570=== PAUSE TestSkippedUploadsHandler571=== RUN TestSystemdListenerNotActivated572--- PASS: TestSystemdListenerNotActivated (0.00s)573=== RUN TestWatchdogBeatsWhenHealthy574--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)575=== RUN TestWatchdogSkipsWhenUnhealthy5762026/09/13 15:16:04 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5772026/09/13 15:16:04 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5782026/09/13 15:16:04 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5792026/09/13 15:16:04 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5802026/09/13 15:16:04 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5812026/09/13 15:16:04 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5822026/09/13 15:16:04 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5832026/09/13 15:16:04 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5842026/09/13 15:16:04 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5852026/09/13 15:16:04 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"586--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)587=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle588=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle589=== RUN TestProxyWriteTimeout590=== PAUSE TestProxyWriteTimeout591=== RUN TestIsValidUploadKey592=== PAUSE TestIsValidUploadKey593=== RUN TestUploadHandlersRejectInvalidKeys594=== PAUSE TestUploadHandlersRejectInvalidKeys595=== RUN TestUploadHandlersRejectOversizedBody596=== PAUSE TestUploadHandlersRejectOversizedBody597=== RUN TestService_cleanupPendingClosuresHandler598=== PAUSE TestService_cleanupPendingClosuresHandler599=== RUN TestService_createPendingClosureHandler600=== PAUSE TestService_createPendingClosureHandler601=== RUN TestService_verifyS3Integrity602=== PAUSE TestService_verifyS3Integrity603=== RUN TestCompleteMultipartUnregistered604=== PAUSE TestCompleteMultipartUnregistered605=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT606=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT607=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle608=== CONT TestService_AuthMiddleware609=== CONT TestSkippedUploadsHandler610=== CONT TestParseSize611=== CONT TestService_Rustfstest612--- PASS: TestParseSize (0.00s)613=== CONT TestReadProxyNarinfo614=== CONT TestPresignedUploadRegisteredBeforeCommit615=== CONT TestCompleteMultipartUpload_ErrorButObjectExists616=== CONT TestRedundantMultipartUpload6172026/09/13 15:16:04 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000618=== CONT TestReadRedirectUsesPublicS3URL619=== CONT TestReadProxyRangeRequest620=== CONT TestReadRedirectKeepsNarinfoProxied621=== CONT TestReadRedirectNar622=== CONT TestReadProxyDisabled623=== CONT TestReadProxyRootRedirectsToIndexHTML624=== CONT TestReadProxyConditionalGet625=== CONT TestReadProxyHead626=== CONT TestService_cleanupPendingClosuresHandler627=== CONT TestReadProxyInvalidPath628=== CONT TestReadProxy404629=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT630=== CONT TestReadProxyNarStreaming631=== CONT TestCompleteMultipartUnregistered632=== CONT TestReadProxyNarinfoAlreadyDecompressed633=== CONT TestCompletedNarNotReofferedAcrossClosures634--- PASS: TestSkippedUploadsHandler (0.01s)635=== CONT TestService_verifyS3Integrity6362026-09-13 15:16:04.321 UTC [610] ERROR: relation "goose_db_version" does not exist at character 366372026-09-13 15:16:04.321 UTC [610] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6382026-09-13 15:16:04.335 UTC [611] ERROR: relation "goose_db_version" does not exist at character 366392026-09-13 15:16:04.335 UTC [611] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6402026-09-13 15:16:04.343 UTC [612] ERROR: relation "goose_db_version" does not exist at character 366412026-09-13 15:16:04.343 UTC [612] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6422026-09-13 15:16:04.384 UTC [613] ERROR: relation "goose_db_version" does not exist at character 366432026-09-13 15:16:04.384 UTC [613] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6442026/09/13 15:16:04 OK 20241026095416_initial_model.sql (63.59ms)6452026-09-13 15:16:04.419 UTC [614] ERROR: relation "goose_db_version" does not exist at character 366462026-09-13 15:16:04.419 UTC [614] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6472026-09-13 15:16:04.421 UTC [615] ERROR: relation "goose_db_version" does not exist at character 366482026-09-13 15:16:04.421 UTC [615] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6492026/09/13 15:16:04 OK 20241026095416_initial_model.sql (64.45ms)6502026/09/13 15:16:04 OK 20241026095416_initial_model.sql (74.59ms)6512026/09/13 15:16:04 OK 20251210153512_drop_unused_gin_index.sql (4.66ms)6522026/09/13 15:16:04 OK 20251210153512_drop_unused_gin_index.sql (4.05ms)6532026/09/13 15:16:04 OK 20251210153512_drop_unused_gin_index.sql (9.68ms)6542026/09/13 15:16:04 OK 20251218171726_add_pins.sql (10.07ms)6552026-09-13 15:16:04.436 UTC [619] ERROR: relation "goose_db_version" does not exist at character 366562026-09-13 15:16:04.436 UTC [619] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6572026-09-13 15:16:04.437 UTC [618] ERROR: relation "goose_db_version" does not exist at character 366582026-09-13 15:16:04.437 UTC [618] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6592026/09/13 15:16:04 OK 20251218171726_add_pins.sql (13.76ms)6602026/09/13 15:16:04 OK 20241026095416_initial_model.sql (25.57ms)6612026-09-13 15:16:04.448 UTC [620] ERROR: relation "goose_db_version" does not exist at character 366622026-09-13 15:16:04.448 UTC [620] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6632026/09/13 15:16:04 OK 20251218171726_add_pins.sql (18.64ms)6642026/09/13 15:16:04 OK 20260628120000_add_object_size_and_stats.sql (16.67ms)6652026/09/13 15:16:04 OK 20260628120000_add_object_size_and_stats.sql (18.01ms)6662026/09/13 15:16:04 OK 20251210153512_drop_unused_gin_index.sql (11.64ms)6672026/09/13 15:16:04 OK 20241026095416_initial_model.sql (27.31ms)6682026/09/13 15:16:04 OK 20260628120000_add_object_size_and_stats.sql (12.85ms)6692026/09/13 15:16:04 OK 20260905000000_add_claims.sql (12.79ms)6702026/09/13 15:16:04 goose: successfully migrated database to version: 202609050000006712026/09/13 15:16:04 OK 20251218171726_add_pins.sql (20.39ms)6722026/09/13 15:16:04 OK 20260905000000_add_claims.sql (22.7ms)6732026/09/13 15:16:04 OK 20241026095416_initial_model.sql (41.64ms)6742026/09/13 15:16:04 goose: successfully migrated database to version: 202609050000006752026/09/13 15:16:04 OK 20251210153512_drop_unused_gin_index.sql (14.39ms)6762026/09/13 15:16:04 OK 1_commit_pending_closure.sql (14.48ms)6772026/09/13 15:16:04 OK 20260905000000_add_claims.sql (18.68ms)6782026/09/13 15:16:04 goose: successfully migrated database to version: 202609050000006792026/09/13 15:16:04 OK 2_object_stats_trigger.sql (5.87ms)6802026/09/13 15:16:04 goose: up to current file version: 26812026/09/13 15:16:04 OK 1_commit_pending_closure.sql (6.36ms)6822026/09/13 15:16:04 OK 20251218171726_add_pins.sql (8.16ms)6832026/09/13 15:16:04 OK 20260628120000_add_object_size_and_stats.sql (10.96ms)6842026/09/13 15:16:04 OK 20251210153512_drop_unused_gin_index.sql (4.45ms)6852026/09/13 15:16:04 OK 20241026095416_initial_model.sql (34.11ms)6862026/09/13 15:16:04 OK 1_commit_pending_closure.sql (6.48ms)6872026/09/13 15:16:04 OK 20241026095416_initial_model.sql (34.05ms)6882026/09/13 15:16:04 OK 2_object_stats_trigger.sql (4.64ms)6892026/09/13 15:16:04 goose: up to current file version: 26902026/09/13 15:16:04 OK 20251210153512_drop_unused_gin_index.sql (4.56ms)6912026/09/13 15:16:04 OK 20260905000000_add_claims.sql (8.11ms)6922026/09/13 15:16:04 goose: successfully migrated database to version: 202609050000006932026/09/13 15:16:04 OK 2_object_stats_trigger.sql (5.39ms)6942026/09/13 15:16:04 goose: up to current file version: 26952026/09/13 15:16:04 OK 20251210153512_drop_unused_gin_index.sql (5.71ms)6962026/09/13 15:16:04 OK 20251218171726_add_pins.sql (9.47ms)6972026/09/13 15:16:04 OK 20260628120000_add_object_size_and_stats.sql (10.07ms)6982026/09/13 15:16:04 OK 20241026095416_initial_model.sql (32.67ms)6992026/09/13 15:16:04 OK 1_commit_pending_closure.sql (5.84ms)7002026/09/13 15:16:04 OK 20251218171726_add_pins.sql (7.83ms)7012026/09/13 15:16:04 OK 20251218171726_add_pins.sql (13.21ms)7022026-09-13 15:16:04.512 UTC [622] ERROR: relation "goose_db_version" does not exist at character 367032026-09-13 15:16:04.512 UTC [622] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7042026/09/13 15:16:04 OK 20260628120000_add_object_size_and_stats.sql (11.49ms)7052026/09/13 15:16:04 OK 20260905000000_add_claims.sql (15.84ms)7062026/09/13 15:16:04 goose: successfully migrated database to version: 202609050000007072026/09/13 15:16:04 OK 2_object_stats_trigger.sql (11.6ms)7082026/09/13 15:16:04 goose: up to current file version: 27092026/09/13 15:16:04 OK 20260628120000_add_object_size_and_stats.sql (16ms)7102026/09/13 15:16:04 OK 20251210153512_drop_unused_gin_index.sql (14.03ms)7112026-09-13 15:16:04.515 UTC [623] ERROR: relation "goose_db_version" does not exist at character 367122026-09-13 15:16:04.515 UTC [623] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7132026/09/13 15:16:04 OK 20260628120000_add_object_size_and_stats.sql (8.94ms)7142026/09/13 15:16:04 OK 1_commit_pending_closure.sql (4.81ms)7152026/09/13 15:16:04 OK 20260905000000_add_claims.sql (5.71ms)7162026/09/13 15:16:04 goose: successfully migrated database to version: 202609050000007172026-09-13 15:16:04.522 UTC [624] ERROR: relation "goose_db_version" does not exist at character 367182026-09-13 15:16:04.522 UTC [624] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7192026/09/13 15:16:04 OK 20260905000000_add_claims.sql (9.79ms)7202026/09/13 15:16:04 goose: successfully migrated database to version: 202609050000007212026/09/13 15:16:04 OK 2_object_stats_trigger.sql (5ms)7222026/09/13 15:16:04 goose: up to current file version: 27232026/09/13 15:16:04 OK 20251218171726_add_pins.sql (9.65ms)7242026-09-13 15:16:04.525 UTC [625] ERROR: relation "goose_db_version" does not exist at character 367252026-09-13 15:16:04.525 UTC [625] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7262026/09/13 15:16:04 OK 1_commit_pending_closure.sql (4.98ms)7272026/09/13 15:16:04 OK 20260905000000_add_claims.sql (6.45ms)7282026/09/13 15:16:04 goose: successfully migrated database to version: 202609050000007292026/09/13 15:16:04 OK 1_commit_pending_closure.sql (3.07ms)7302026-09-13 15:16:04.528 UTC [627] ERROR: relation "goose_db_version" does not exist at character 367312026-09-13 15:16:04.528 UTC [627] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7322026-09-13 15:16:04.528 UTC [626] ERROR: relation "goose_db_version" does not exist at character 367332026-09-13 15:16:04.528 UTC [626] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7342026-09-13 15:16:04.529 UTC [628] ERROR: relation "goose_db_version" does not exist at character 367352026-09-13 15:16:04.529 UTC [628] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7362026/09/13 15:16:04 OK 2_object_stats_trigger.sql (3.8ms)7372026/09/13 15:16:04 goose: up to current file version: 27382026-09-13 15:16:04.530 UTC [629] ERROR: relation "goose_db_version" does not exist at character 367392026-09-13 15:16:04.530 UTC [629] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7402026-09-13 15:16:04.531 UTC [630] ERROR: relation "goose_db_version" does not exist at character 367412026-09-13 15:16:04.531 UTC [630] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7422026/09/13 15:16:04 OK 2_object_stats_trigger.sql (4.17ms)7432026/09/13 15:16:04 goose: up to current file version: 27442026/09/13 15:16:04 OK 1_commit_pending_closure.sql (5.97ms)7452026/09/13 15:16:04 OK 20260628120000_add_object_size_and_stats.sql (7ms)7462026-09-13 15:16:04.532 UTC [631] ERROR: relation "goose_db_version" does not exist at character 367472026-09-13 15:16:04.532 UTC [631] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7482026-09-13 15:16:04.535 UTC [632] ERROR: relation "goose_db_version" does not exist at character 367492026-09-13 15:16:04.535 UTC [632] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7502026/09/13 15:16:04 OK 2_object_stats_trigger.sql (4.76ms)7512026/09/13 15:16:04 goose: up to current file version: 27522026/09/13 15:16:04 OK 20241026095416_initial_model.sql (15.95ms)7532026-09-13 15:16:04.537 UTC [633] ERROR: relation "goose_db_version" does not exist at character 367542026-09-13 15:16:04.537 UTC [633] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7552026-09-13 15:16:04.538 UTC [634] ERROR: relation "goose_db_version" does not exist at character 367562026-09-13 15:16:04.538 UTC [634] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7572026/09/13 15:16:04 OK 20241026095416_initial_model.sql (11.7ms)7582026/09/13 15:16:04 OK 20260905000000_add_claims.sql (6.94ms)7592026/09/13 15:16:04 goose: successfully migrated database to version: 202609050000007602026-09-13 15:16:04.539 UTC [635] ERROR: relation "goose_db_version" does not exist at character 367612026-09-13 15:16:04.539 UTC [635] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7622026-09-13 15:16:04.541 UTC [636] ERROR: relation "goose_db_version" does not exist at character 367632026-09-13 15:16:04.541 UTC [636] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7642026/09/13 15:16:04 OK 20251210153512_drop_unused_gin_index.sql (4.03ms)7652026/09/13 15:16:04 OK 20251210153512_drop_unused_gin_index.sql (3.54ms)7662026/09/13 15:16:04 OK 1_commit_pending_closure.sql (6.31ms)7672026/09/13 15:16:04 OK 20251218171726_add_pins.sql (5.94ms)7682026/09/13 15:16:04 OK 20241026095416_initial_model.sql (14.54ms)7692026/09/13 15:16:04 OK 20251218171726_add_pins.sql (5.88ms)7702026/09/13 15:16:04 OK 20241026095416_initial_model.sql (12.69ms)7712026/09/13 15:16:04 OK 2_object_stats_trigger.sql (4.13ms)7722026/09/13 15:16:04 goose: up to current file version: 27732026/09/13 15:16:04 OK 20251210153512_drop_unused_gin_index.sql (2.9ms)7742026/09/13 15:16:04 OK 20251210153512_drop_unused_gin_index.sql (3.4ms)7752026/09/13 15:16:04 OK 20260628120000_add_object_size_and_stats.sql (6.1ms)7762026/09/13 15:16:04 OK 20241026095416_initial_model.sql (15.49ms)7772026/09/13 15:16:04 OK 20260628120000_add_object_size_and_stats.sql (6.38ms)7782026/09/13 15:16:04 OK 20241026095416_initial_model.sql (15.37ms)7792026/09/13 15:16:04 OK 20251218171726_add_pins.sql (6.48ms)7802026/09/13 15:16:04 OK 20241026095416_initial_model.sql (17.45ms)7812026/09/13 15:16:04 OK 20241026095416_initial_model.sql (15.6ms)7822026/09/13 15:16:04 OK 20251210153512_drop_unused_gin_index.sql (3.79ms)7832026/09/13 15:16:04 OK 20241026095416_initial_model.sql (17.22ms)7842026/09/13 15:16:04 OK 20260905000000_add_claims.sql (5.81ms)7852026/09/13 15:16:04 goose: successfully migrated database to version: 202609050000007862026/09/13 15:16:04 OK 20251218171726_add_pins.sql (6.99ms)7872026/09/13 15:16:04 OK 20241026095416_initial_model.sql (16.15ms)7882026/09/13 15:16:04 OK 20251210153512_drop_unused_gin_index.sql (4.16ms)7892026/09/13 15:16:04 OK 20260905000000_add_claims.sql (6.47ms)7902026/09/13 15:16:04 goose: successfully migrated database to version: 202609050000007912026/09/13 15:16:04 OK 20251210153512_drop_unused_gin_index.sql (4.51ms)7922026/09/13 15:16:04 OK 20251210153512_drop_unused_gin_index.sql (4.74ms)7932026/09/13 15:16:04 OK 20241026095416_initial_model.sql (18.7ms)7942026/09/13 15:16:04 OK 20251210153512_drop_unused_gin_index.sql (4.72ms)7952026/09/13 15:16:04 OK 20241026095416_initial_model.sql (16.43ms)7962026/09/13 15:16:04 OK 20251218171726_add_pins.sql (6.35ms)7972026/09/13 15:16:04 OK 20241026095416_initial_model.sql (15.86ms)7982026/09/13 15:16:04 OK 20241026095416_initial_model.sql (13.83ms)7992026/09/13 15:16:04 OK 20251210153512_drop_unused_gin_index.sql (4.48ms)8002026/09/13 15:16:04 OK 1_commit_pending_closure.sql (5.8ms)8012026/09/13 15:16:04 OK 20260628120000_add_object_size_and_stats.sql (8.28ms)8022026/09/13 15:16:04 OK 1_commit_pending_closure.sql (3.56ms)8032026/09/13 15:16:04 OK 20251210153512_drop_unused_gin_index.sql (3.34ms)8042026/09/13 15:16:04 OK 20251210153512_drop_unused_gin_index.sql (3.18ms)8052026/09/13 15:16:04 OK 20260628120000_add_object_size_and_stats.sql (7.73ms)8062026/09/13 15:16:04 OK 20251218171726_add_pins.sql (7.59ms)8072026/09/13 15:16:04 OK 20251210153512_drop_unused_gin_index.sql (3.43ms)8082026/09/13 15:16:04 OK 2_object_stats_trigger.sql (3.09ms)8092026/09/13 15:16:04 goose: up to current file version: 28102026/09/13 15:16:04 OK 20241026095416_initial_model.sql (18.89ms)8112026/09/13 15:16:04 OK 2_object_stats_trigger.sql (3.51ms)8122026/09/13 15:16:04 goose: up to current file version: 28132026/09/13 15:16:04 OK 20251218171726_add_pins.sql (6.56ms)8142026/09/13 15:16:04 OK 20251210153512_drop_unused_gin_index.sql (4.82ms)8152026/09/13 15:16:04 OK 20260905000000_add_claims.sql (4.62ms)8162026/09/13 15:16:04 OK 20251218171726_add_pins.sql (8.11ms)8172026/09/13 15:16:04 OK 20251218171726_add_pins.sql (5.87ms)8182026/09/13 15:16:04 goose: successfully migrated database to version: 202609050000008192026/09/13 15:16:04 OK 20260628120000_add_object_size_and_stats.sql (6.01ms)8202026/09/13 15:16:04 OK 20251218171726_add_pins.sql (4.54ms)8212026/09/13 15:16:04 OK 20251218171726_add_pins.sql (8.05ms)8222026/09/13 15:16:04 OK 20251218171726_add_pins.sql (5.78ms)8232026/09/13 15:16:04 OK 20260905000000_add_claims.sql (3.93ms)8242026/09/13 15:16:04 goose: successfully migrated database to version: 202609050000008252026/09/13 15:16:04 OK 20251218171726_add_pins.sql (5.15ms)8262026/09/13 15:16:04 OK 20260628120000_add_object_size_and_stats.sql (5.23ms)8272026/09/13 15:16:04 OK 20251210153512_drop_unused_gin_index.sql (4.18ms)8282026/09/13 15:16:04 OK 1_commit_pending_closure.sql (3.72ms)8292026/09/13 15:16:04 OK 20251218171726_add_pins.sql (7.13ms)8302026/09/13 15:16:04 OK 20260905000000_add_claims.sql (5.78ms)8312026/09/13 15:16:04 goose: successfully migrated database to version: 202609050000008322026/09/13 15:16:04 OK 1_commit_pending_closure.sql (4.62ms)8332026/09/13 15:16:04 OK 20260628120000_add_object_size_and_stats.sql (7.19ms)8342026/09/13 15:16:04 OK 20260628120000_add_object_size_and_stats.sql (6.07ms)8352026/09/13 15:16:04 OK 2_object_stats_trigger.sql (3.29ms)8362026/09/13 15:16:04 goose: up to current file version: 28372026/09/13 15:16:04 OK 20260628120000_add_object_size_and_stats.sql (6.78ms)8382026/09/13 15:16:04 OK 20260905000000_add_claims.sql (4.6ms)8392026/09/13 15:16:04 goose: successfully migrated database to version: 202609050000008402026/09/13 15:16:04 OK 20251218171726_add_pins.sql (4.38ms)8412026/09/13 15:16:04 OK 20260628120000_add_object_size_and_stats.sql (5.02ms)8422026/09/13 15:16:04 OK 20260628120000_add_object_size_and_stats.sql (6.04ms)8432026/09/13 15:16:04 OK 20260628120000_add_object_size_and_stats.sql (6.86ms)8442026/09/13 15:16:04 OK 2_object_stats_trigger.sql (1.41ms)8452026/09/13 15:16:04 goose: up to current file version: 28462026/09/13 15:16:04 OK 20260628120000_add_object_size_and_stats.sql (7.33ms)8472026/09/13 15:16:04 OK 1_commit_pending_closure.sql (3.37ms)8482026/09/13 15:16:04 OK 20260628120000_add_object_size_and_stats.sql (5.61ms)8492026/09/13 15:16:04 OK 20260905000000_add_claims.sql (5.4ms)8502026/09/13 15:16:04 goose: successfully migrated database to version: 202609050000008512026/09/13 15:16:04 OK 20260905000000_add_claims.sql (4.77ms)8522026/09/13 15:16:04 goose: successfully migrated database to version: 202609050000008532026/09/13 15:16:04 OK 1_commit_pending_closure.sql (5.42ms)8542026/09/13 15:16:04 OK 2_object_stats_trigger.sql (3.09ms)8552026/09/13 15:16:04 goose: up to current file version: 28562026/09/13 15:16:04 OK 20260905000000_add_claims.sql (5.42ms)8572026/09/13 15:16:04 goose: successfully migrated database to version: 202609050000008582026/09/13 15:16:04 OK 20260905000000_add_claims.sql (5.06ms)8592026/09/13 15:16:04 goose: successfully migrated database to version: 202609050000008602026/09/13 15:16:04 OK 20260628120000_add_object_size_and_stats.sql (5.47ms)8612026/09/13 15:16:04 OK 20260905000000_add_claims.sql (5.68ms)8622026/09/13 15:16:04 goose: successfully migrated database to version: 202609050000008632026/09/13 15:16:04 OK 20260905000000_add_claims.sql (5.28ms)8642026/09/13 15:16:04 goose: successfully migrated database to version: 202609050000008652026/09/13 15:16:04 OK 20260905000000_add_claims.sql (5.37ms)8662026/09/13 15:16:04 goose: successfully migrated database to version: 202609050000008672026/09/13 15:16:04 OK 1_commit_pending_closure.sql (2.74ms)8682026/09/13 15:16:04 OK 2_object_stats_trigger.sql (2.79ms)8692026/09/13 15:16:04 goose: up to current file version: 28702026/09/13 15:16:04 OK 1_commit_pending_closure.sql (3.7ms)8712026/09/13 15:16:04 OK 20260905000000_add_claims.sql (4.02ms)8722026/09/13 15:16:04 goose: successfully migrated database to version: 202609050000008732026/09/13 15:16:04 OK 1_commit_pending_closure.sql (2.45ms)8742026/09/13 15:16:04 OK 1_commit_pending_closure.sql (2.64ms)8752026/09/13 15:16:04 OK 1_commit_pending_closure.sql (2.89ms)8762026/09/13 15:16:04 OK 2_object_stats_trigger.sql (1.45ms)8772026/09/13 15:16:04 goose: up to current file version: 28782026/09/13 15:16:04 OK 1_commit_pending_closure.sql (2.56ms)8792026/09/13 15:16:04 OK 1_commit_pending_closure.sql (3.14ms)8802026/09/13 15:16:04 OK 2_object_stats_trigger.sql (1ms)8812026/09/13 15:16:04 goose: up to current file version: 28822026/09/13 15:16:04 OK 2_object_stats_trigger.sql (1.27ms)8832026/09/13 15:16:04 goose: up to current file version: 28842026/09/13 15:16:04 OK 2_object_stats_trigger.sql (1.52ms)8852026/09/13 15:16:04 goose: up to current file version: 28862026/09/13 15:16:04 OK 2_object_stats_trigger.sql (1.25ms)8872026/09/13 15:16:04 goose: up to current file version: 28882026/09/13 15:16:04 OK 2_object_stats_trigger.sql (1.19ms)8892026/09/13 15:16:04 goose: up to current file version: 28902026/09/13 15:16:04 OK 20260905000000_add_claims.sql (4.47ms)8912026/09/13 15:16:04 goose: successfully migrated database to version: 202609050000008922026/09/13 15:16:04 OK 2_object_stats_trigger.sql (1.64ms)8932026/09/13 15:16:04 goose: up to current file version: 28942026/09/13 15:16:04 OK 1_commit_pending_closure.sql (2.24ms)8952026/09/13 15:16:04 OK 2_object_stats_trigger.sql (687.35µs)8962026/09/13 15:16:04 goose: up to current file version: 28972026/09/13 15:16:04 OK 1_commit_pending_closure.sql (1.32ms)8982026/09/13 15:16:04 OK 2_object_stats_trigger.sql (780.01µs)8992026/09/13 15:16:04 goose: up to current file version: 29002026/09/13 15:16:04 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"901--- PASS: TestService_AuthMiddleware (0.37s)902=== CONT TestIsValidCachePath903=== RUN TestIsValidCachePath/narinfo904=== PAUSE TestIsValidCachePath/narinfo905=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars906=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars907=== RUN TestIsValidCachePath/nar_zst908=== PAUSE TestIsValidCachePath/nar_zst909=== RUN TestIsValidCachePath/nar_xz910=== PAUSE TestIsValidCachePath/nar_xz911=== RUN TestIsValidCachePath/nar_bz2912=== PAUSE TestIsValidCachePath/nar_bz2913=== RUN TestIsValidCachePath/nar_uncompressed914=== PAUSE TestIsValidCachePath/nar_uncompressed915=== RUN TestIsValidCachePath/ls916=== PAUSE TestIsValidCachePath/ls917=== RUN TestIsValidCachePath/log918=== PAUSE TestIsValidCachePath/log919=== RUN TestIsValidCachePath/realisation920=== PAUSE TestIsValidCachePath/realisation921=== RUN TestIsValidCachePath/nix-cache-info922=== PAUSE TestIsValidCachePath/nix-cache-info923=== RUN TestIsValidCachePath/index.html924=== PAUSE TestIsValidCachePath/index.html925=== RUN TestIsValidCachePath/traversal_parent926=== PAUSE TestIsValidCachePath/traversal_parent927=== RUN TestIsValidCachePath/traversal_in_middle928=== PAUSE TestIsValidCachePath/traversal_in_middle929=== RUN TestIsValidCachePath/invalid_char_e930=== PAUSE TestIsValidCachePath/invalid_char_e931=== RUN TestIsValidCachePath/invalid_char_u932=== PAUSE TestIsValidCachePath/invalid_char_u933=== RUN TestIsValidCachePath/random_path934=== PAUSE TestIsValidCachePath/random_path935=== RUN TestIsValidCachePath/empty936=== PAUSE TestIsValidCachePath/empty937=== RUN TestIsValidCachePath/leading_slash938=== PAUSE TestIsValidCachePath/leading_slash939=== RUN TestIsValidCachePath/wrong_extension940=== PAUSE TestIsValidCachePath/wrong_extension941=== RUN TestIsValidCachePath/short_hash942=== PAUSE TestIsValidCachePath/short_hash943=== CONT TestService_createPendingClosureHandler9442026/09/13 15:16:04 INFO Received uploads request method=POST path=/api/pending_closures945--- PASS: TestService_Rustfstest (0.44s)946=== CONT TestParseSingleRange947=== RUN TestParseSingleRange/none948=== PAUSE TestParseSingleRange/none949=== RUN TestParseSingleRange/unknown_unit950=== PAUSE TestParseSingleRange/unknown_unit951=== RUN TestParseSingleRange/multi-range_ignored952=== PAUSE TestParseSingleRange/multi-range_ignored953=== RUN TestParseSingleRange/malformed_no_dash954=== PAUSE TestParseSingleRange/malformed_no_dash955=== RUN TestParseSingleRange/malformed_both_empty956=== PAUSE TestParseSingleRange/malformed_both_empty957=== RUN TestParseSingleRange/malformed_end_before_start958=== PAUSE TestParseSingleRange/malformed_end_before_start959=== RUN TestParseSingleRange/closed960=== PAUSE TestParseSingleRange/closed961=== RUN TestParseSingleRange/open-ended962=== PAUSE TestParseSingleRange/open-ended963=== RUN TestParseSingleRange/end_clamped_to_size964=== PAUSE TestParseSingleRange/end_clamped_to_size965=== RUN TestParseSingleRange/suffix966=== PAUSE TestParseSingleRange/suffix967=== RUN TestParseSingleRange/suffix_exceeds_size968=== PAUSE TestParseSingleRange/suffix_exceeds_size969=== RUN TestParseSingleRange/single_byte970=== PAUSE TestParseSingleRange/single_byte971=== RUN TestParseSingleRange/start_past_EOF972=== PAUSE TestParseSingleRange/start_past_EOF973=== RUN TestParseSingleRange/start_far_past_EOF974=== PAUSE TestParseSingleRange/start_far_past_EOF975=== CONT TestResurrectedObjectNotDeleted9762026-09-13 15:16:04.676 UTC [639] ERROR: relation "goose_db_version" does not exist at character 369772026-09-13 15:16:04.676 UTC [639] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9782026/09/13 15:16:04 OK 20241026095416_initial_model.sql (14.64ms)9792026/09/13 15:16:04 OK 20251210153512_drop_unused_gin_index.sql (5.05ms)9802026/09/13 15:16:04 OK 20251218171726_add_pins.sql (5.68ms)9812026/09/13 15:16:04 OK 20260628120000_add_object_size_and_stats.sql (4.82ms)9822026/09/13 15:16:04 OK 20260905000000_add_claims.sql (4.78ms)9832026/09/13 15:16:04 goose: successfully migrated database to version: 202609050000009842026/09/13 15:16:04 OK 1_commit_pending_closure.sql (4.11ms)9852026/09/13 15:16:04 OK 2_object_stats_trigger.sql (2.25ms)9862026/09/13 15:16:04 goose: up to current file version: 2987--- PASS: TestReadRedirectNar (0.50s)988=== CONT TestUploadHandlersRejectInvalidKeys989=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info990=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info991=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal992=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal993=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key994=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key995=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key9962026/09/13 15:16:04 INFO Received uploads request method=POST path=/api/pending_closures997=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key998=== CONT TestOrphanedObjectsGCStressTest9992026-09-13 15:16:04.750 UTC [644] ERROR: relation "goose_db_version" does not exist at character 3610002026-09-13 15:16:04.750 UTC [644] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10012026/09/13 15:16:04 OK 20241026095416_initial_model.sql (14.3ms)10022026/09/13 15:16:04 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1003--- PASS: TestReadProxyDisabled (0.56s)10042026/09/13 15:16:04 OK 20251210153512_drop_unused_gin_index.sql (3.79ms)1005=== CONT TestUploadHandlersRejectOversizedBody10062026/09/13 15:16:04 OK 20251218171726_add_pins.sql (6.53ms)10072026/09/13 15:16:04 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=YTM4NDNmOWQtM2YyZC00Yzg5LTg4ZTEtOWZhMGU5ZGYwMDJjLmEwYThhNDE2LWJkNWQtNDYyYi05OTgyLWI2NDQxODAyNTUwZngxNzg5MzEyNTY0NzQxODc0NzY510082026/09/13 15:16:04 OK 20260628120000_add_object_size_and_stats.sql (5.68ms)10092026/09/13 15:16:04 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=YTM4NDNmOWQtM2YyZC00Yzg5LTg4ZTEtOWZhMGU5ZGYwMDJjLmEwYThhNDE2LWJkNWQtNDYyYi05OTgyLWI2NDQxODAyNTUwZngxNzg5MzEyNTY0NzQxODc0NzY5 parts=11010--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (0.57s)1011=== CONT TestOrphanedObjectsGC10122026/09/13 15:16:04 OK 20260905000000_add_claims.sql (4.75ms)10132026/09/13 15:16:04 goose: successfully migrated database to version: 2026090500000010142026-09-13 15:16:04.811 UTC [646] ERROR: relation "goose_db_version" does not exist at character 3610152026-09-13 15:16:04.811 UTC [646] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10162026/09/13 15:16:04 OK 1_commit_pending_closure.sql (2.73ms)10172026/09/13 15:16:04 OK 2_object_stats_trigger.sql (2.34ms)10182026/09/13 15:16:04 goose: up to current file version: 210192026/09/13 15:16:04 OK 20241026095416_initial_model.sql (14.69ms)10202026/09/13 15:16:04 OK 20251210153512_drop_unused_gin_index.sql (3.81ms)10212026/09/13 15:16:04 INFO Received uploads request method=POST path=/api/pending_closures1022--- PASS: TestReadProxyNarinfo (0.62s)1023=== CONT TestObjectStatsTrigger10242026/09/13 15:16:04 OK 20251218171726_add_pins.sql (4.91ms)10252026/09/13 15:16:04 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10262026/09/13 15:16:04 OK 20260628120000_add_object_size_and_stats.sql (5.35ms)10272026/09/13 15:16:04 OK 20260905000000_add_claims.sql (4.31ms)10282026/09/13 15:16:04 goose: successfully migrated database to version: 2026090500000010292026/09/13 15:16:04 OK 1_commit_pending_closure.sql (2.74ms)10302026/09/13 15:16:04 OK 2_object_stats_trigger.sql (2.79ms)10312026/09/13 15:16:04 goose: up to current file version: 210322026/09/13 15:16:04 INFO Received uploads request method=POST path=/api/pending_closures10332026/09/13 15:16:04 INFO Received uploads request method=POST path=/api/pending_closures10342026-09-13 15:16:04.884 UTC [650] ERROR: relation "goose_db_version" does not exist at character 3610352026-09-13 15:16:04.884 UTC [650] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1036--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.66s)1037=== CONT TestPinProtectsFromGC10382026/09/13 15:16:04 OK 20241026095416_initial_model.sql (12.76ms)1039--- PASS: TestReadProxyRootRedirectsToIndexHTML (0.67s)1040=== CONT TestClientWithDependencies10412026/09/13 15:16:04 OK 20251210153512_drop_unused_gin_index.sql (2.46ms)10422026/09/13 15:16:04 OK 20251218171726_add_pins.sql (4.31ms)10432026/09/13 15:16:04 OK 20260628120000_add_object_size_and_stats.sql (6.78ms)10442026/09/13 15:16:04 OK 20260905000000_add_claims.sql (4.57ms)10452026/09/13 15:16:04 goose: successfully migrated database to version: 2026090500000010462026/09/13 15:16:04 OK 1_commit_pending_closure.sql (4.54ms)10472026-09-13 15:16:04.927 UTC [655] ERROR: relation "goose_db_version" does not exist at character 3610482026-09-13 15:16:04.927 UTC [655] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10492026/09/13 15:16:04 OK 2_object_stats_trigger.sql (3.55ms)10502026/09/13 15:16:04 goose: up to current file version: 210512026/09/13 15:16:04 OK 20241026095416_initial_model.sql (25.33ms)10522026/09/13 15:16:04 OK 20251210153512_drop_unused_gin_index.sql (3.94ms)10532026/09/13 15:16:04 OK 20251218171726_add_pins.sql (4.94ms)10542026-09-13 15:16:04.975 UTC [656] ERROR: relation "goose_db_version" does not exist at character 3610552026-09-13 15:16:04.975 UTC [656] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10562026/09/13 15:16:04 OK 20260628120000_add_object_size_and_stats.sql (4.94ms)10572026/09/13 15:16:04 OK 20260905000000_add_claims.sql (3.19ms)10582026/09/13 15:16:04 goose: successfully migrated database to version: 2026090500000010592026/09/13 15:16:04 OK 1_commit_pending_closure.sql (2.81ms)10602026/09/13 15:16:04 OK 2_object_stats_trigger.sql (1.46ms)10612026/09/13 15:16:04 goose: up to current file version: 21062=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure1063=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure1064=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart1065=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart1066=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts1067=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts1068=== CONT TestMultipartCleanup10692026/09/13 15:16:04 OK 20241026095416_initial_model.sql (10.09ms)10702026-09-13 15:16:04.992 UTC [657] ERROR: relation "goose_db_version" does not exist at character 3610712026-09-13 15:16:04.992 UTC [657] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10722026/09/13 15:16:04 OK 20251210153512_drop_unused_gin_index.sql (1.57ms)10732026/09/13 15:16:04 OK 20251218171726_add_pins.sql (3.87ms)10742026/09/13 15:16:05 OK 20260628120000_add_object_size_and_stats.sql (3.21ms)10752026/09/13 15:16:05 OK 20260905000000_add_claims.sql (4.03ms)10762026/09/13 15:16:05 goose: successfully migrated database to version: 2026090500000010772026/09/13 15:16:05 OK 1_commit_pending_closure.sql (3.49ms)10782026/09/13 15:16:05 OK 20241026095416_initial_model.sql (12.39ms)10792026/09/13 15:16:05 OK 2_object_stats_trigger.sql (2.31ms)10802026/09/13 15:16:05 goose: up to current file version: 210812026/09/13 15:16:05 OK 20251210153512_drop_unused_gin_index.sql (3.82ms)10822026/09/13 15:16:05 OK 20251218171726_add_pins.sql (4.64ms)10832026/09/13 15:16:05 OK 20260628120000_add_object_size_and_stats.sql (5.63ms)10842026/09/13 15:16:05 OK 20260905000000_add_claims.sql (4ms)10852026/09/13 15:16:05 goose: successfully migrated database to version: 2026090500000010862026/09/13 15:16:05 OK 1_commit_pending_closure.sql (3.53ms)10872026/09/13 15:16:05 OK 2_object_stats_trigger.sql (2.04ms)10882026/09/13 15:16:05 goose: up to current file version: 210892026-09-13 15:16:05.060 UTC [660] ERROR: relation "goose_db_version" does not exist at character 3610902026-09-13 15:16:05.060 UTC [660] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10912026/09/13 15:16:05 OK 20241026095416_initial_model.sql (10.16ms)10922026/09/13 15:16:05 OK 20251210153512_drop_unused_gin_index.sql (1.3ms)10932026/09/13 15:16:05 OK 20251218171726_add_pins.sql (3.69ms)10942026/09/13 15:16:05 OK 20260628120000_add_object_size_and_stats.sql (2.84ms)10952026/09/13 15:16:05 OK 20260905000000_add_claims.sql (2.95ms)10962026/09/13 15:16:05 goose: successfully migrated database to version: 2026090500000010972026/09/13 15:16:05 OK 1_commit_pending_closure.sql (1.93ms)10982026/09/13 15:16:05 OK 2_object_stats_trigger.sql (843.13µs)10992026/09/13 15:16:05 goose: up to current file version: 211002026/09/13 15:16:06 INFO Received uploads request method=POST path=/api/pending_closures1101--- PASS: TestReadProxyRangeRequest (1.90s)1102=== CONT TestClientMultipleUploads1103--- PASS: TestReadProxyHead (1.91s)1104=== CONT TestServerTLSConfig1105=== RUN TestServerTLSConfig/no_client_CA1106=== PAUSE TestServerTLSConfig/no_client_CA1107=== RUN TestServerTLSConfig/missing_CA_file1108=== PAUSE TestServerTLSConfig/missing_CA_file1109=== RUN TestServerTLSConfig/not_a_PEM_file1110=== PAUSE TestServerTLSConfig/not_a_PEM_file1111=== CONT TestClientIntegration1112--- PASS: TestReadProxy404 (1.94s)1113=== CONT TestService_NativeMTLS11142026/09/13 15:16:06 INFO Received uploads request method=POST path=/api/pending_closures11152026-09-13 15:16:06.203 UTC [667] ERROR: relation "goose_db_version" does not exist at character 3611162026-09-13 15:16:06.203 UTC [667] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11172026/09/13 15:16:06 OK 20241026095416_initial_model.sql (11.98ms)11182026/09/13 15:16:06 OK 20251210153512_drop_unused_gin_index.sql (2.91ms)11192026/09/13 15:16:06 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst11202026/09/13 15:16:06 INFO Received uploads request method=POST path=/api/pending_closures11212026/09/13 15:16:06 OK 20251218171726_add_pins.sql (4.25ms)1122--- PASS: TestPresignedUploadRegisteredBeforeCommit (2.02s)1123=== CONT TestClientErrorHandling1124=== RUN TestClientErrorHandling/InvalidStorePath1125=== PAUSE TestClientErrorHandling/InvalidStorePath1126=== RUN TestClientErrorHandling/InvalidAuthToken1127=== PAUSE TestClientErrorHandling/InvalidAuthToken1128=== RUN TestClientErrorHandling/ServerNotAvailable1129=== PAUSE TestClientErrorHandling/ServerNotAvailable1130=== CONT TestMetricsInventory11312026-09-13 15:16:06.248 UTC [669] ERROR: relation "goose_db_version" does not exist at character 3611322026-09-13 15:16:06.248 UTC [669] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11332026/09/13 15:16:06 OK 20260628120000_add_object_size_and_stats.sql (4.15ms)11342026/09/13 15:16:06 OK 20260905000000_add_claims.sql (3.08ms)11352026/09/13 15:16:06 goose: successfully migrated database to version: 2026090500000011362026/09/13 15:16:06 OK 1_commit_pending_closure.sql (1.94ms)11372026/09/13 15:16:06 OK 2_object_stats_trigger.sql (926.35µs)11382026/09/13 15:16:06 goose: up to current file version: 21139--- PASS: TestReadProxyNarinfoAlreadyDecompressed (2.03s)1140=== CONT TestClientCADerivations11412026-09-13 15:16:06.263 UTC [672] ERROR: relation "goose_db_version" does not exist at character 3611422026-09-13 15:16:06.263 UTC [672] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11432026/09/13 15:16:06 OK 20241026095416_initial_model.sql (13.1ms)11442026/09/13 15:16:06 OK 20251210153512_drop_unused_gin_index.sql (4.21ms)11452026/09/13 15:16:06 OK 20251218171726_add_pins.sql (4.66ms)11462026/09/13 15:16:06 OK 20260628120000_add_object_size_and_stats.sql (5.2ms)11472026/09/13 15:16:06 OK 20241026095416_initial_model.sql (12.89ms)11482026/09/13 15:16:06 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11492026/09/13 15:16:06 OK 20251210153512_drop_unused_gin_index.sql (3.9ms)11502026/09/13 15:16:06 OK 20260905000000_add_claims.sql (6.87ms)11512026/09/13 15:16:06 goose: successfully migrated database to version: 2026090500000011522026/09/13 15:16:06 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst1153--- PASS: TestCompleteMultipartUnregistered (2.05s)1154=== CONT TestNARDeduplicationMetadataUploadBug11552026/09/13 15:16:06 OK 1_commit_pending_closure.sql (4.24ms)11562026/09/13 15:16:06 OK 20251218171726_add_pins.sql (6.77ms)11572026/09/13 15:16:06 OK 2_object_stats_trigger.sql (3.37ms)11582026/09/13 15:16:06 goose: up to current file version: 211592026/09/13 15:16:06 OK 20260628120000_add_object_size_and_stats.sql (5.32ms)11602026/09/13 15:16:06 OK 20260905000000_add_claims.sql (5.06ms)11612026/09/13 15:16:06 goose: successfully migrated database to version: 2026090500000011622026/09/13 15:16:06 OK 1_commit_pending_closure.sql (3.46ms)11632026/09/13 15:16:06 OK 2_object_stats_trigger.sql (2.55ms)11642026/09/13 15:16:06 goose: up to current file version: 21165--- PASS: TestReadProxyConditionalGet (2.09s)1166=== CONT TestClaim_StreamsThroughServer11672026-09-13 15:16:06.329 UTC [677] ERROR: relation "goose_db_version" does not exist at character 3611682026-09-13 15:16:06.329 UTC [677] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11692026/09/13 15:16:06 OK 20241026095416_initial_model.sql (12.62ms)11702026-09-13 15:16:06.356 UTC [680] ERROR: relation "goose_db_version" does not exist at character 3611712026-09-13 15:16:06.356 UTC [680] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1172--- PASS: TestReadRedirectKeepsNarinfoProxied (2.13s)1173=== CONT TestCreatePendingClosureRejectsOversizedNAR11742026/09/13 15:16:06 INFO Received uploads request method=POST path=/api/pending_closures1175--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)1176=== CONT TestClaim_InputsTouched11772026/09/13 15:16:06 OK 20251210153512_drop_unused_gin_index.sql (3.06ms)11782026/09/13 15:16:06 OK 20251218171726_add_pins.sql (4.36ms)11792026/09/13 15:16:06 OK 20260628120000_add_object_size_and_stats.sql (5.25ms)11802026/09/13 15:16:06 OK 20260905000000_add_claims.sql (5.98ms)11812026/09/13 15:16:06 goose: successfully migrated database to version: 2026090500000011822026/09/13 15:16:06 OK 20241026095416_initial_model.sql (11.66ms)11832026/09/13 15:16:06 OK 1_commit_pending_closure.sql (6.17ms)11842026-09-13 15:16:06.383 UTC [683] ERROR: relation "goose_db_version" does not exist at character 3611852026-09-13 15:16:06.383 UTC [683] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11862026/09/13 15:16:06 OK 20251210153512_drop_unused_gin_index.sql (5.65ms)11872026/09/13 15:16:06 OK 2_object_stats_trigger.sql (2.89ms)11882026/09/13 15:16:06 goose: up to current file version: 21189--- PASS: TestReadProxyInvalidPath (2.15s)1190=== CONT TestCacheConfigHandlerMaxNarSize1191--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)1192=== CONT TestClaim_TwoInstances11932026/09/13 15:16:06 OK 20251218171726_add_pins.sql (10.26ms)11942026/09/13 15:16:06 OK 20260628120000_add_object_size_and_stats.sql (5.87ms)11952026/09/13 15:16:06 OK 20260905000000_add_claims.sql (6.24ms)11962026/09/13 15:16:06 goose: successfully migrated database to version: 2026090500000011972026-09-13 15:16:06.410 UTC [686] ERROR: relation "goose_db_version" does not exist at character 3611982026-09-13 15:16:06.410 UTC [686] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11992026/09/13 15:16:06 OK 20241026095416_initial_model.sql (15.53ms)12002026/09/13 15:16:06 OK 1_commit_pending_closure.sql (9.03ms)12012026/09/13 15:16:06 OK 20251210153512_drop_unused_gin_index.sql (7.67ms)12022026/09/13 15:16:06 OK 2_object_stats_trigger.sql (5.14ms)12032026/09/13 15:16:06 goose: up to current file version: 212042026/09/13 15:16:06 INFO Received cleanup request method=DELETE path=/api/pending_closures12052026/09/13 15:16:06 OK 20251218171726_add_pins.sql (6.84ms)12062026/09/13 15:16:06 INFO Aborted multipart uploads count=012072026/09/13 15:16:06 OK 20260628120000_add_object_size_and_stats.sql (10.28ms)12082026/09/13 15:16:06 INFO Received uploads request method=POST path=/api/pending_closures12092026/09/13 15:16:06 OK 20241026095416_initial_model.sql (24.73ms)12102026/09/13 15:16:06 OK 20260905000000_add_claims.sql (10.09ms)12112026/09/13 15:16:06 goose: successfully migrated database to version: 2026090500000012122026/09/13 15:16:06 OK 20251210153512_drop_unused_gin_index.sql (3.35ms)12132026/09/13 15:16:06 OK 1_commit_pending_closure.sql (2.42ms)12142026/09/13 15:16:06 OK 2_object_stats_trigger.sql (1.1ms)12152026/09/13 15:16:06 goose: up to current file version: 212162026/09/13 15:16:06 OK 20251218171726_add_pins.sql (3.49ms)12172026/09/13 15:16:06 INFO Received uploads request method=POST path=/api/pending_closures12182026/09/13 15:16:06 INFO Received cleanup request method=DELETE path=/api/pending_closures12192026/09/13 15:16:06 OK 20260628120000_add_object_size_and_stats.sql (4.05ms)12202026/09/13 15:16:06 INFO Aborted multipart uploads count=112212026-09-13 15:16:06.461 UTC [688] ERROR: relation "goose_db_version" does not exist at character 3612222026-09-13 15:16:06.461 UTC [688] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12232026/09/13 15:16:06 OK 20260905000000_add_claims.sql (5.31ms)12242026/09/13 15:16:06 goose: successfully migrated database to version: 2026090500000012252026-09-13 15:16:06.462 UTC [687] ERROR: relation "goose_db_version" does not exist at character 3612262026-09-13 15:16:06.462 UTC [687] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12272026/09/13 15:16:06 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete12282026-09-13 15:16:06.464 UTC [628] ERROR: Closure does not exist: id=112292026-09-13 15:16:06.464 UTC [628] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 16 at RAISE12302026-09-13 15:16:06.464 UTC [628] STATEMENT: -- name: CommitPendingClosure :exec1231 SELECT commit_pending_closure($1::bigint)1232 1233--- PASS: TestService_cleanupPendingClosuresHandler (2.23s)1234=== CONT TestGenerateLandingPage12352026/09/13 15:16:06 OK 1_commit_pending_closure.sql (3.94ms)12362026/09/13 15:16:06 OK 2_object_stats_trigger.sql (1.03ms)12372026/09/13 15:16:06 goose: up to current file version: 21238--- PASS: TestGenerateLandingPage (0.01s)1239=== CONT TestClaim_StaleHeartbeatStolen12402026/09/13 15:16:06 OK 20241026095416_initial_model.sql (13.94ms)12412026/09/13 15:16:06 OK 20241026095416_initial_model.sql (13.86ms)12422026/09/13 15:16:06 OK 20251210153512_drop_unused_gin_index.sql (6.62ms)12432026/09/13 15:16:06 OK 20251210153512_drop_unused_gin_index.sql (6.94ms)12442026/09/13 15:16:06 OK 20251218171726_add_pins.sql (4.35ms)12452026/09/13 15:16:06 OK 20251218171726_add_pins.sql (5.5ms)12462026/09/13 15:16:06 OK 20260628120000_add_object_size_and_stats.sql (4.02ms)12472026/09/13 15:16:06 OK 20260628120000_add_object_size_and_stats.sql (11.13ms)12482026/09/13 15:16:06 OK 20260905000000_add_claims.sql (10.05ms)12492026/09/13 15:16:06 goose: successfully migrated database to version: 2026090500000012502026/09/13 15:16:06 OK 20260905000000_add_claims.sql (4.75ms)12512026/09/13 15:16:06 goose: successfully migrated database to version: 2026090500000012522026/09/13 15:16:06 OK 1_commit_pending_closure.sql (4.25ms)1253--- PASS: TestReadRedirectUsesPublicS3URL (2.28s)1254=== CONT TestService_readinessHandler12552026/09/13 15:16:06 OK 1_commit_pending_closure.sql (4.97ms)12562026/09/13 15:16:06 OK 2_object_stats_trigger.sql (5.64ms)12572026/09/13 15:16:06 goose: up to current file version: 212582026/09/13 15:16:06 OK 2_object_stats_trigger.sql (4.6ms)12592026/09/13 15:16:06 goose: up to current file version: 21260--- PASS: TestReadProxyNarStreaming (2.30s)1261=== CONT TestClaim_FailWithoutKindReleases12622026-09-13 15:16:06.563 UTC [695] ERROR: relation "goose_db_version" does not exist at character 3612632026-09-13 15:16:06.563 UTC [695] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12642026/09/13 15:16:06 OK 20241026095416_initial_model.sql (16.11ms)12652026/09/13 15:16:06 OK 20251210153512_drop_unused_gin_index.sql (2.44ms)12662026/09/13 15:16:06 OK 20251218171726_add_pins.sql (4.22ms)12672026-09-13 15:16:06.601 UTC [696] ERROR: relation "goose_db_version" does not exist at character 3612682026-09-13 15:16:06.601 UTC [696] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12692026/09/13 15:16:06 OK 20260628120000_add_object_size_and_stats.sql (5.31ms)12702026/09/13 15:16:06 OK 20260905000000_add_claims.sql (3.12ms)12712026/09/13 15:16:06 goose: successfully migrated database to version: 2026090500000012722026/09/13 15:16:06 OK 1_commit_pending_closure.sql (2.15ms)12732026/09/13 15:16:06 OK 2_object_stats_trigger.sql (996.65µs)12742026/09/13 15:16:06 goose: up to current file version: 212752026-09-13 15:16:06.619 UTC [697] ERROR: relation "goose_db_version" does not exist at character 3612762026-09-13 15:16:06.619 UTC [697] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12772026/09/13 15:16:06 OK 20241026095416_initial_model.sql (11.18ms)12782026/09/13 15:16:06 OK 20251210153512_drop_unused_gin_index.sql (2.02ms)12792026/09/13 15:16:06 OK 20251218171726_add_pins.sql (3.86ms)12802026/09/13 15:16:06 OK 20260628120000_add_object_size_and_stats.sql (4.54ms)12812026/09/13 15:16:06 OK 20260905000000_add_claims.sql (4.45ms)12822026/09/13 15:16:06 goose: successfully migrated database to version: 2026090500000012832026/09/13 15:16:06 OK 20241026095416_initial_model.sql (10.78ms)12842026/09/13 15:16:06 OK 1_commit_pending_closure.sql (2.28ms)12852026/09/13 15:16:06 OK 2_object_stats_trigger.sql (1ms)12862026/09/13 15:16:06 goose: up to current file version: 212872026/09/13 15:16:06 OK 20251210153512_drop_unused_gin_index.sql (1.44ms)12882026/09/13 15:16:06 OK 20251218171726_add_pins.sql (3.67ms)12892026/09/13 15:16:06 OK 20260628120000_add_object_size_and_stats.sql (3.69ms)12902026/09/13 15:16:06 OK 20260905000000_add_claims.sql (2.81ms)12912026/09/13 15:16:06 goose: successfully migrated database to version: 2026090500000012922026/09/13 15:16:06 OK 1_commit_pending_closure.sql (2.01ms)12932026/09/13 15:16:06 OK 2_object_stats_trigger.sql (824.53µs)12942026/09/13 15:16:06 goose: up to current file version: 212952026/09/13 15:16:08 INFO Received uploads request method=POST path=/api/pending_closures12962026/09/13 15:16:08 INFO Received uploads request method=POST path=/api/pending_closures12972026/09/13 15:16:08 INFO Received uploads request method=POST path=/api/pending_closures1298--- PASS: TestResurrectedObjectNotDeleted (3.52s)1299=== CONT TestService_healthCheckHandler13002026-09-13 15:16:08.274 UTC [704] ERROR: relation "goose_db_version" does not exist at character 3613012026-09-13 15:16:08.274 UTC [704] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13022026/09/13 15:16:08 OK 20241026095416_initial_model.sql (10.76ms)13032026/09/13 15:16:08 OK 20251210153512_drop_unused_gin_index.sql (1.34ms)13042026/09/13 15:16:08 OK 20251218171726_add_pins.sql (3.59ms)13052026/09/13 15:16:08 OK 20260628120000_add_object_size_and_stats.sql (5.31ms)13062026/09/13 15:16:08 OK 20260905000000_add_claims.sql (3.84ms)13072026/09/13 15:16:08 goose: successfully migrated database to version: 2026090500000013082026/09/13 15:16:08 OK 1_commit_pending_closure.sql (2.18ms)13092026/09/13 15:16:08 OK 2_object_stats_trigger.sql (919.01µs)13102026/09/13 15:16:08 goose: up to current file version: 213112026/09/13 15:16:08 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13122026/09/13 15:16:08 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=YTM4NDNmOWQtM2YyZC00Yzg5LTg4ZTEtOWZhMGU5ZGYwMDJjLjY0MTFhZjYxLTAyZTItNDI4MS04ZjI2LTQ4ZjgxNmU1MTM4MngxNzg5MzEyNTY2MDk3OTQ5NDM4 parts=1213132026/09/13 15:16:08 INFO Received uploads request method=POST path=/api/pending_closures1314--- PASS: TestCompletedNarNotReofferedAcrossClosures (4.57s)1315=== CONT TestClaim_FailWakesWaitersButIsNotRemembered13162026-09-13 15:16:08.870 UTC [723] ERROR: relation "goose_db_version" does not exist at character 3613172026-09-13 15:16:08.870 UTC [723] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13182026/09/13 15:16:08 OK 20241026095416_initial_model.sql (9.7ms)13192026/09/13 15:16:08 OK 20251210153512_drop_unused_gin_index.sql (1.47ms)13202026/09/13 15:16:08 OK 20251218171726_add_pins.sql (3.27ms)13212026/09/13 15:16:08 OK 20260628120000_add_object_size_and_stats.sql (2.85ms)13222026/09/13 15:16:08 OK 20260905000000_add_claims.sql (3.41ms)13232026/09/13 15:16:08 goose: successfully migrated database to version: 2026090500000013242026/09/13 15:16:08 OK 1_commit_pending_closure.sql (1.99ms)13252026/09/13 15:16:08 OK 2_object_stats_trigger.sql (856.23µs)13262026/09/13 15:16:08 goose: up to current file version: 21327--- PASS: TestObjectStatsTrigger (4.53s)1328=== CONT TestGracefulShutdownDrainsInflight13292026/09/13 15:16:09 INFO Starting HTTP server address=127.0.0.1:3461713302026/09/13 15:16:09 INFO Shutdown signal received, draining in-flight requests timeout=10s13312026/09/13 15:16:09 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13322026/09/13 15:16:09 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=YTM4NDNmOWQtM2YyZC00Yzg5LTg4ZTEtOWZhMGU5ZGYwMDJjLjZiMGEwYTY2LTM3ZWEtNDgzZS1hMDAxLWQ3YzVkNzA1NGNkYngxNzg5MzEyNTY0ODU3Njc0OTQ5 parts=121333--- PASS: TestRedundantMultipartUpload (5.18s)1334=== CONT TestClaim_HolderDisconnectKeepsClaim1335--- PASS: TestGracefulShutdownDrainsInflight (0.07s)1336=== CONT TestGCTaskStore_Fail1337--- PASS: TestGCTaskStore_Fail (0.00s)1338=== CONT TestClaim_TooManyStreams13392026/09/13 15:16:09 INFO Received uploads request method=POST path=/api/pending_closures13402026-09-13 15:16:09.497 UTC [763] ERROR: relation "goose_db_version" does not exist at character 3613412026-09-13 15:16:09.497 UTC [763] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1342=== NAME TestPinProtectsFromGC1343 client_integration_test.go:648: Pinned store path: /build/TestPinProtectsFromGC3782420718/001/store/0xpyw7im44lz7s5hzdfihyflygp8haab-pinned-file.txt1344 client_integration_test.go:649: Unpinned store path: /build/TestPinProtectsFromGC3782420718/001/store/ydvb7f1m1qgi34qcscpcmbxpdrsjkzj8-unpinned-file.txt1345=== NAME TestClientWithDependencies1346 client_integration_test.go:594: Built derivation: /build/TestClientWithDependencies1792018721/001/store/5lkpkbvfcwdrvw9if761i1xcmbjcc47a-test-script13472026/09/13 15:16:09 OK 20241026095416_initial_model.sql (28.5ms)13482026/09/13 15:16:09 OK 20251210153512_drop_unused_gin_index.sql (2.33ms)13492026/09/13 15:16:09 OK 20251218171726_add_pins.sql (4.32ms)13502026-09-13 15:16:09.554 UTC [801] ERROR: relation "goose_db_version" does not exist at character 3613512026-09-13 15:16:09.554 UTC [801] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13522026/09/13 15:16:09 OK 20260628120000_add_object_size_and_stats.sql (4.54ms)13532026/09/13 15:16:09 OK 20260905000000_add_claims.sql (3.82ms)13542026/09/13 15:16:09 goose: successfully migrated database to version: 2026090500000013552026/09/13 15:16:09 OK 1_commit_pending_closure.sql (2.03ms)13562026/09/13 15:16:09 OK 2_object_stats_trigger.sql (972.51µs)13572026/09/13 15:16:09 goose: up to current file version: 213582026/09/13 15:16:09 OK 20241026095416_initial_model.sql (7.77ms)13592026/09/13 15:16:09 OK 20251210153512_drop_unused_gin_index.sql (1.27ms)13602026/09/13 15:16:09 OK 20251218171726_add_pins.sql (2.31ms)1361 client_integration_test.go:596: Found 1 dependencies (including self)13622026/09/13 15:16:09 OK 20260628120000_add_object_size_and_stats.sql (3.05ms)1363=== NAME TestClientMultipleUploads13642026/09/13 15:16:09 OK 20260905000000_add_claims.sql (3.58ms)1365 client_integration_test.go:339: Created store path 0: /build/TestClientMultipleUploads4060421895/001/store/8pl231h6b64pwy68ksg11zzmgbngazra-test-file-0.txt13662026/09/13 15:16:09 goose: successfully migrated database to version: 2026090500000013672026/09/13 15:16:09 OK 1_commit_pending_closure.sql (2.48ms)13682026/09/13 15:16:09 INFO Received cleanup request method=DELETE path=/api/pending_closures13692026/09/13 15:16:09 OK 2_object_stats_trigger.sql (1.38ms)13702026/09/13 15:16:09 goose: up to current file version: 213712026/09/13 15:16:09 INFO Aborted multipart uploads count=11372--- PASS: TestMultipartCleanup (4.61s)1373=== CONT TestGCTaskStore_PhaseUpdates1374--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)1375=== CONT TestClaim_GCMarkedOutputCountsAsAbsent1376=== NAME TestClientIntegration1377 client_integration_test.go:277: Created store path: /build/TestClientIntegration33144556/002/store/dqg48rvdsli8h5y53jhmnghry0s7sc0j-test-file.txt13782026/09/13 15:16:09 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"1379=== NAME TestClientMultipleUploads1380 client_integration_test.go:339: Created store path 1: /build/TestClientMultipleUploads4060421895/001/store/qndayxh3fa1g18ic089rzkddyrhhrb3m-test-file-1.txt13812026/09/13 15:16:09 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"13822026/09/13 15:16:09 INFO Received uploads request method=POST path=/api/pending_closures13832026/09/13 15:16:09 INFO Received uploads request method=POST path=/api/pending_closures13842026/09/13 15:16:09 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)13852026/09/13 15:16:09 INFO Uploading 5lkpkbvfcwdrvw9if761i1xcmbjcc47a-test-script (136B)13862026/09/13 15:16:09 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)13872026/09/13 15:16:09 INFO Uploading 0xpyw7im44lz7s5hzdfihyflygp8haab-pinned-file.txt (128B)13882026-09-13 15:16:09.667 UTC [980] ERROR: relation "goose_db_version" does not exist at character 3613892026-09-13 15:16:09.667 UTC [980] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13902026/09/13 15:16:09 WARN Failed to register uploaded object key=log/zdnzp51c2ivzw893pklqi5pn94mr8xz7-test-script.drv error="server returned 404: 404 page not found\n"13912026/09/13 15:16:09 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"13922026/09/13 15:16:09 WARN mTLS auth: subject not in bound subjects subject="CN=reader"13932026/09/13 15:16:09 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1394--- PASS: TestService_NativeMTLS (3.50s)1395=== CONT TestGCTaskStore_CompletedAllowsNewTask1396--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)1397=== CONT TestClaim_BuildWaitComplete1398=== NAME TestClientMultipleUploads1399 client_integration_test.go:339: Created store path 2: /build/TestClientMultipleUploads4060421895/001/store/pd05mwqvsbwpy84bzqb5ljd01d7slpsq-test-file-2.txt14002026/09/13 15:16:09 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"14012026/09/13 15:16:09 WARN Failed to register uploaded object key=5lkpkbvfcwdrvw9if761i1xcmbjcc47a.ls error="server returned 404: 404 page not found\n"14022026/09/13 15:16:09 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign14032026/09/13 15:16:09 INFO Signed narinfos id=1 count=114042026/09/13 15:16:09 INFO Uploading 1 narinfos14052026/09/13 15:16:09 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"14062026/09/13 15:16:09 WARN Failed to register uploaded object key=0xpyw7im44lz7s5hzdfihyflygp8haab.ls error="server returned 404: 404 page not found\n"14072026/09/13 15:16:09 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign14082026/09/13 15:16:09 INFO Signed narinfos id=1 count=114092026/09/13 15:16:09 INFO Uploading 1 narinfos1410=== NAME TestOrphanedObjectsGC1411 orphaned_objects_gc_test.go:290: GC Test Summary:1412 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A1413 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B1414 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)1415 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)1416 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects1417--- PASS: TestOrphanedObjectsGC (4.88s)1418=== CONT TestCacheStatsHandler14192026/09/13 15:16:09 WARN Failed to register uploaded object key=5lkpkbvfcwdrvw9if761i1xcmbjcc47a.narinfo error="server returned 404: 404 page not found\n"14202026/09/13 15:16:09 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete14212026/09/13 15:16:09 WARN Failed to register uploaded object key=0xpyw7im44lz7s5hzdfihyflygp8haab.narinfo error="server returned 404: 404 page not found\n"14222026/09/13 15:16:09 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete14232026/09/13 15:16:09 OK 20241026095416_initial_model.sql (11.94ms)14242026/09/13 15:16:09 OK 20251210153512_drop_unused_gin_index.sql (2.25ms)14252026/09/13 15:16:09 OK 20251218171726_add_pins.sql (4.63ms)14262026/09/13 15:16:09 INFO Completed upload id=114272026/09/13 15:16:09 INFO Upload complete. (84ms)14282026/09/13 15:16:09 INFO Completed upload id=114292026/09/13 15:16:09 INFO Upload complete. (115ms)14302026/09/13 15:16:09 WARN Rate limiter enabled after throttle name=s3-test rate=514312026/09/13 15:16:09 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."1432=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle1433 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=101434 throttle_test.go:215: Rate limiter: enabled=true, rate=5.0014352026/09/13 15:16:09 OK 20260628120000_add_object_size_and_stats.sql (4.94ms)1436--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (5.47s)1437=== CONT TestGCTaskStore_GetReturnsLatest1438--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)1439=== CONT TestIsValidUploadKey1440=== RUN TestIsValidUploadKey/narinfo1441=== PAUSE TestIsValidUploadKey/narinfo1442=== RUN TestIsValidUploadKey/nar_zst1443=== PAUSE TestIsValidUploadKey/nar_zst1444=== RUN TestIsValidUploadKey/nar_xz1445=== PAUSE TestIsValidUploadKey/nar_xz1446=== NAME TestClientWithDependencies1447 client_integration_test.go:598: Skipping nix copy test - isolated store (/build/TestClientWithDependencies1792018721/001/store) requires matching store prefix1448=== RUN TestIsValidUploadKey/nar_plain1449=== PAUSE TestIsValidUploadKey/nar_plain1450=== RUN TestIsValidUploadKey/listing1451=== PAUSE TestIsValidUploadKey/listing1452=== RUN TestIsValidUploadKey/build_log1453=== PAUSE TestIsValidUploadKey/build_log1454=== RUN TestIsValidUploadKey/build_log_home-manager_file1455=== PAUSE TestIsValidUploadKey/build_log_home-manager_file1456=== RUN TestIsValidUploadKey/build_log_plus_in_name1457=== PAUSE TestIsValidUploadKey/build_log_plus_in_name1458=== RUN TestIsValidUploadKey/build_log_question_mark1459=== PAUSE TestIsValidUploadKey/build_log_question_mark1460=== RUN TestIsValidUploadKey/build_log_equals1461=== PAUSE TestIsValidUploadKey/build_log_equals1462=== RUN TestIsValidUploadKey/realisation1463=== PAUSE TestIsValidUploadKey/realisation1464=== RUN TestIsValidUploadKey/realisation_plus_in_output1465=== PAUSE TestIsValidUploadKey/realisation_plus_in_output1466=== RUN TestIsValidUploadKey/nix-cache-info1467=== PAUSE TestIsValidUploadKey/nix-cache-info1468=== RUN TestIsValidUploadKey/index.html1469=== PAUSE TestIsValidUploadKey/index.html1470=== RUN TestIsValidUploadKey/narinfo_key,_nar_type1471=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type1472=== RUN TestIsValidUploadKey/nar_key,_narinfo_type1473=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type1474=== RUN TestIsValidUploadKey/listing_key,_narinfo_type1475=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type1476=== RUN TestIsValidUploadKey/traversal1477=== PAUSE TestIsValidUploadKey/traversal1478=== RUN TestIsValidUploadKey/traversal_nar1479=== PAUSE TestIsValidUploadKey/traversal_nar1480=== RUN TestIsValidUploadKey/absolute1481=== PAUSE TestIsValidUploadKey/absolute1482=== RUN TestIsValidUploadKey/empty_key1483=== PAUSE TestIsValidUploadKey/empty_key1484=== RUN TestIsValidUploadKey/unknown_type1485=== PAUSE TestIsValidUploadKey/unknown_type1486=== CONT TestCacheConfigHandler1487=== RUN TestCacheConfigHandler/full_config,_no_issuer1488=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1489=== RUN TestCacheConfigHandler/no_cache_url_configured1490=== PAUSE TestCacheConfigHandler/no_cache_url_configured1491=== RUN TestCacheConfigHandler/no_signing_keys1492=== PAUSE TestCacheConfigHandler/no_signing_keys1493=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1494=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1495=== CONT TestProxyWriteTimeout1496=== RUN TestProxyWriteTimeout/narinfo1497=== PAUSE TestProxyWriteTimeout/narinfo1498=== RUN TestProxyWriteTimeout/1_GiB_nar1499=== PAUSE TestProxyWriteTimeout/1_GiB_nar1500=== RUN TestProxyWriteTimeout/10_GiB_nar1501=== PAUSE TestProxyWriteTimeout/10_GiB_nar1502=== RUN TestProxyWriteTimeout/unknown_size1503=== PAUSE TestProxyWriteTimeout/unknown_size1504=== CONT TestService_ReadScope_PublicByDefault15052026/09/13 15:16:09 OK 20260905000000_add_claims.sql (4.81ms)15062026/09/13 15:16:09 goose: successfully migrated database to version: 202609050000001507--- PASS: TestClientWithDependencies (4.80s)1508=== CONT TestService_RequireScope_OIDC15092026/09/13 15:16:09 OK 1_commit_pending_closure.sql (3.42ms)15102026/09/13 15:16:09 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:35809/oidc15112026/09/13 15:16:09 OK 2_object_stats_trigger.sql (2.35ms)15122026/09/13 15:16:09 goose: up to current file version: 215132026/09/13 15:16:09 INFO Received uploads request method=POST path=/api/pending_closures1514--- PASS: TestMetricsInventory (3.47s)1515=== CONT TestService_AuthMiddleware_OIDC15162026/09/13 15:16:09 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:41939/oidc15172026/09/13 15:16:09 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15182026/09/13 15:16:09 INFO Uploading dqg48rvdsli8h5y53jhmnghry0s7sc0j-test-file.txt (152B)15192026/09/13 15:16:09 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"15202026/09/13 15:16:09 WARN Failed to register uploaded object key=dqg48rvdsli8h5y53jhmnghry0s7sc0j.ls error="server returned 404: 404 page not found\n"15212026/09/13 15:16:09 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign15222026/09/13 15:16:09 INFO Signed narinfos id=1 count=115232026/09/13 15:16:09 INFO Uploading 1 narinfos15242026/09/13 15:16:09 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"15252026/09/13 15:16:09 WARN Failed to register uploaded object key=dqg48rvdsli8h5y53jhmnghry0s7sc0j.narinfo error="server returned 404: 404 page not found\n"15262026/09/13 15:16:09 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete15272026/09/13 15:16:09 INFO Completed upload id=115282026/09/13 15:16:09 INFO Upload complete. (121ms)1529=== NAME TestClientIntegration1530 client_integration_test.go:293: Retrieved narinfo from S3:1531 StorePath: /build/TestClientIntegration33144556/002/store/dqg48rvdsli8h5y53jhmnghry0s7sc0j-test-file.txt1532 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1533 Compression: zstd1534 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11535 NarSize: 1521536 References: 1537 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk115382026-09-13 15:16:09.766 UTC [1100] ERROR: relation "goose_db_version" does not exist at character 3615392026-09-13 15:16:09.766 UTC [1100] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15402026/09/13 15:16:09 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"15412026-09-13 15:16:09.781 UTC [1129] ERROR: relation "goose_db_version" does not exist at character 3615422026-09-13 15:16:09.781 UTC [1129] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15432026/09/13 15:16:09 INFO Received uploads request method=POST path=/api/pending_closures15442026/09/13 15:16:09 OK 20241026095416_initial_model.sql (13.8ms)15452026/09/13 15:16:09 OK 20251210153512_drop_unused_gin_index.sql (2.7ms)15462026/09/13 15:16:09 INFO Received uploads request method=POST path=/api/pending_closures15472026/09/13 15:16:09 OK 20251218171726_add_pins.sql (5.28ms)15482026/09/13 15:16:09 INFO Received uploads request method=POST path=/api/pending_closures15492026-09-13 15:16:09.799 UTC [1156] ERROR: relation "goose_db_version" does not exist at character 3615502026-09-13 15:16:09.799 UTC [1156] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15512026/09/13 15:16:09 OK 20241026095416_initial_model.sql (12.9ms)15522026/09/13 15:16:09 OK 20260628120000_add_object_size_and_stats.sql (4.77ms)15532026/09/13 15:16:09 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)15542026/09/13 15:16:09 INFO Uploading qndayxh3fa1g18ic089rzkddyrhhrb3m-test-file-1.txt (160B)15552026/09/13 15:16:09 INFO Uploading 8pl231h6b64pwy68ksg11zzmgbngazra-test-file-0.txt (160B)15562026/09/13 15:16:09 INFO Uploading pd05mwqvsbwpy84bzqb5ljd01d7slpsq-test-file-2.txt (160B)15572026/09/13 15:16:09 OK 20251210153512_drop_unused_gin_index.sql (3.28ms)15582026/09/13 15:16:09 OK 20260905000000_add_claims.sql (4.43ms)15592026/09/13 15:16:09 goose: successfully migrated database to version: 2026090500000015602026-09-13 15:16:09.807 UTC [1157] ERROR: relation "goose_db_version" does not exist at character 3615612026-09-13 15:16:09.807 UTC [1157] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15622026/09/13 15:16:09 OK 20251218171726_add_pins.sql (5.06ms)15632026/09/13 15:16:09 INFO Received uploads request method=POST path=/api/pending_closures15642026/09/13 15:16:09 OK 1_commit_pending_closure.sql (4.06ms)15652026/09/13 15:16:09 OK 2_object_stats_trigger.sql (2.54ms)15662026/09/13 15:16:09 goose: up to current file version: 215672026/09/13 15:16:09 OK 20260628120000_add_object_size_and_stats.sql (4.62ms)15682026/09/13 15:16:09 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15692026/09/13 15:16:09 INFO Uploading ydvb7f1m1qgi34qcscpcmbxpdrsjkzj8-unpinned-file.txt (128B)15702026/09/13 15:16:09 OK 20241026095416_initial_model.sql (13.16ms)15712026/09/13 15:16:09 OK 20260905000000_add_claims.sql (5.91ms)15722026/09/13 15:16:09 goose: successfully migrated database to version: 2026090500000015732026/09/13 15:16:09 OK 20251210153512_drop_unused_gin_index.sql (2.58ms)15742026/09/13 15:16:09 OK 1_commit_pending_closure.sql (3.36ms)15752026/09/13 15:16:09 OK 2_object_stats_trigger.sql (1.57ms)15762026/09/13 15:16:09 goose: up to current file version: 215772026/09/13 15:16:09 OK 20251218171726_add_pins.sql (3.84ms)15782026/09/13 15:16:09 OK 20260628120000_add_object_size_and_stats.sql (4.7ms)15792026/09/13 15:16:09 OK 20241026095416_initial_model.sql (15.58ms)15802026/09/13 15:16:09 OK 20251210153512_drop_unused_gin_index.sql (1.84ms)15812026/09/13 15:16:09 OK 20260905000000_add_claims.sql (2.96ms)15822026/09/13 15:16:09 goose: successfully migrated database to version: 2026090500000015832026/09/13 15:16:09 OK 1_commit_pending_closure.sql (2.27ms)15842026/09/13 15:16:09 OK 20251218171726_add_pins.sql (3.87ms)15852026/09/13 15:16:09 OK 2_object_stats_trigger.sql (1.24ms)15862026/09/13 15:16:09 goose: up to current file version: 215872026/09/13 15:16:09 OK 20260628120000_add_object_size_and_stats.sql (4.26ms)1588=== NAME TestClientCADerivations1589 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations2528514457/001/store/y2f119ksxpi0jvrdf1v77wqz7yx84i2j-ca-test15902026/09/13 15:16:09 OK 20260905000000_add_claims.sql (4.06ms)15912026-09-13 15:16:09.845 UTC [1192] ERROR: relation "goose_db_version" does not exist at character 3615922026-09-13 15:16:09.845 UTC [1192] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15932026/09/13 15:16:09 goose: successfully migrated database to version: 2026090500000015942026/09/13 15:16:09 OK 1_commit_pending_closure.sql (2.64ms)15952026/09/13 15:16:09 OK 2_object_stats_trigger.sql (1.13ms)15962026/09/13 15:16:09 goose: up to current file version: 215972026/09/13 15:16:09 OK 20241026095416_initial_model.sql (11.93ms)15982026/09/13 15:16:09 OK 20251210153512_drop_unused_gin_index.sql (1.5ms)15992026/09/13 15:16:09 OK 20251218171726_add_pins.sql (3.69ms)16002026/09/13 15:16:09 OK 20260628120000_add_object_size_and_stats.sql (3.87ms)16012026/09/13 15:16:09 OK 20260905000000_add_claims.sql (3.7ms)16022026/09/13 15:16:09 goose: successfully migrated database to version: 2026090500000016032026/09/13 15:16:09 OK 1_commit_pending_closure.sql (1.88ms)16042026/09/13 15:16:09 OK 2_object_stats_trigger.sql (924.03µs)16052026/09/13 15:16:09 goose: up to current file version: 21606 client_ca_test.go:139: Found 1 dependencies (including self)16072026/09/13 15:16:09 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"16082026/09/13 15:16:09 INFO Received uploads request method=POST path=/api/pending_closures16092026/09/13 15:16:09 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)16102026/09/13 15:16:09 INFO Uploading y2f119ksxpi0jvrdf1v77wqz7yx84i2j-ca-test (144B)16112026/09/13 15:16:10 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"16122026/09/13 15:16:10 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"16132026/09/13 15:16:10 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"16142026/09/13 15:16:10 WARN Failed to register uploaded object key=log/ahhhkgdh85qpnpd20b82gvrcpska4f1s-ca-test.drv error="server returned 404: 404 page not found\n"16152026/09/13 15:16:10 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"16162026/09/13 15:16:10 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"16172026/09/13 15:16:10 WARN Failed to register uploaded object key=pd05mwqvsbwpy84bzqb5ljd01d7slpsq.ls error="server returned 404: 404 page not found\n"16182026/09/13 15:16:10 WARN Failed to register uploaded object key=8pl231h6b64pwy68ksg11zzmgbngazra.ls error="server returned 404: 404 page not found\n"16192026/09/13 15:16:10 WARN Failed to register uploaded object key=y2f119ksxpi0jvrdf1v77wqz7yx84i2j.ls error="server returned 404: 404 page not found\n"16202026/09/13 15:16:10 WARN Failed to register uploaded object key=ydvb7f1m1qgi34qcscpcmbxpdrsjkzj8.ls error="server returned 404: 404 page not found\n"16212026/09/13 15:16:10 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign16222026/09/13 15:16:10 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign16232026/09/13 15:16:10 INFO Signed narinfos id=2 count=116242026/09/13 15:16:10 INFO Uploading 1 narinfos16252026/09/13 15:16:10 INFO Signed narinfos id=1 count=116262026/09/13 15:16:10 INFO Uploading 1 narinfos16272026/09/13 15:16:10 WARN Failed to register uploaded object key=qndayxh3fa1g18ic089rzkddyrhhrb3m.ls error="server returned 404: 404 page not found\n"16282026/09/13 15:16:10 INFO Received sign narinfos request method=POST path=/api/pending_closures/3/sign16292026/09/13 15:16:10 WARN Failed to register uploaded object key=y2f119ksxpi0jvrdf1v77wqz7yx84i2j.narinfo error="server returned 404: 404 page not found\n"16302026/09/13 15:16:10 INFO Signed narinfos id=3 count=116312026/09/13 15:16:10 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete16322026/09/13 15:16:10 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign16332026/09/13 15:16:10 WARN Failed to register uploaded object key=ydvb7f1m1qgi34qcscpcmbxpdrsjkzj8.narinfo error="server returned 404: 404 page not found\n"16342026/09/13 15:16:10 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete16352026/09/13 15:16:10 INFO Signed narinfos id=1 count=116362026/09/13 15:16:10 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign16372026/09/13 15:16:10 INFO Signed narinfos id=2 count=116382026/09/13 15:16:10 INFO Uploading 3 narinfos16392026/09/13 15:16:10 INFO Completed upload id=216402026/09/13 15:16:10 INFO Upload complete. (523ms)16412026/09/13 15:16:10 INFO Completed upload id=116422026/09/13 15:16:10 INFO Upload complete. (342ms)16432026/09/13 15:16:10 WARN Failed to register uploaded object key=pd05mwqvsbwpy84bzqb5ljd01d7slpsq.narinfo error="server returned 404: 404 page not found\n"16442026/09/13 15:16:10 WARN Failed to register uploaded object key=qndayxh3fa1g18ic089rzkddyrhhrb3m.narinfo error="server returned 404: 404 page not found\n"16452026/09/13 15:16:10 WARN Failed to register uploaded object key=8pl231h6b64pwy68ksg11zzmgbngazra.narinfo error="server returned 404: 404 page not found\n"16462026/09/13 15:16:10 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete1647 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations2528514457/001/store/y2f119ksxpi0jvrdf1v77wqz7yx84i2j-ca-test1648 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1649 Compression: zstd1650 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1651 NarSize: 1441652 References: 1653 Deriver: /build/TestClientCADerivations2528514457/001/store/ahhhkgdh85qpnpd20b82gvrcpska4f1s-ca-test.drv1654 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1655 client_ca_test.go:185: Checking for realisation files in S3...1656 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1657 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache16582026/09/13 15:16:10 INFO Completed upload id=116592026/09/13 15:16:10 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete1660=== NAME TestClientIntegration1661 client_integration_test.go:294: Retrieved .ls file from S3 (compressed size: 77 bytes)1662 client_integration_test.go:294: Decompressed .ls content (64 bytes):1663 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1664 client_integration_test.go:297: Testing garbage collection...16652026/09/13 15:16:10 INFO Completed upload id=216662026/09/13 15:16:10 INFO Received complete upload request method=POST path=/api/pending_closures/3/complete16672026/09/13 15:16:10 INFO Completed upload id=316682026/09/13 15:16:10 INFO Upload complete. (561ms)1669=== NAME TestClientMultipleUploads1670 client_integration_test.go:350: Uploaded 3 paths in 599.718669ms1671--- PASS: TestClientMultipleUploads (4.16s)1672=== CONT TestService_ReadAuthMiddleware16732026/09/13 15:16:10 INFO Received create pin request method=POST path=/api/pins/myapp1674=== NAME TestNARDeduplicationMetadataUploadBug1675 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug3147550459/001/store/xla1j5piszx2rbk44nhy0ci9z9m9l2vd-file1.txt16762026/09/13 15:16:10 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC3782420718/001/store/0xpyw7im44lz7s5hzdfihyflygp8haab-pinned-file.txt narinfo_key=0xpyw7im44lz7s5hzdfihyflygp8haab.narinfo16772026/09/13 15:16:10 INFO Starting cleanup of old closures method=DELETE path=/api/closures16782026/09/13 15:16:10 INFO Garbage collection started16792026/09/13 15:16:10 INFO Received uploads request method=POST path=/api/pending_closures16802026/09/13 15:16:10 INFO Starting cleanup of old closures method=DELETE path=/api/closures16812026/09/13 15:16:10 INFO Garbage collection started16822026/09/13 15:16:10 INFO Aborted multipart uploads count=016832026/09/13 15:16:10 INFO Aborted multipart uploads count=016842026/09/13 15:16:10 WARN Force mode enabled - objects will be deleted immediately without grace period16852026/09/13 15:16:10 WARN Force mode enabled - objects will be deleted immediately without grace period16862026/09/13 15:16:10 WARN claim: cannot clear write deadline error="feature not supported"16872026/09/13 15:16:10 WARN claim: cannot clear write deadline error="feature not supported"16882026-09-13 15:16:10.361 UTC [1422] ERROR: relation "goose_db_version" does not exist at character 3616892026-09-13 15:16:10.361 UTC [1422] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16902026/09/13 15:16:10 WARN claim: cannot clear write deadline error="feature not supported"16912026/09/13 15:16:10 INFO Received uploads request method=POST path=/api/pending_closures16922026/09/13 15:16:10 INFO Received complete multipart upload request method=POST path=/api/multipart/complete16932026/09/13 15:16:10 OK 20241026095416_initial_model.sql (9.05ms)16942026/09/13 15:16:10 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"16952026/09/13 15:16:10 OK 20251210153512_drop_unused_gin_index.sql (1.23ms)16962026/09/13 15:16:10 OK 20251218171726_add_pins.sql (3.31ms)16972026/09/13 15:16:10 OK 20260628120000_add_object_size_and_stats.sql (5.71ms)16982026/09/13 15:16:10 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=YTM4NDNmOWQtM2YyZC00Yzg5LTg4ZTEtOWZhMGU5ZGYwMDJjLjRiZTEwNTc4LTZlYmQtNDJjNi1hZWQ3LTg3NmY0NjU1Y2RlMHgxNzg5MzEyNTY2NDY0NzcwMDc0 parts=1016992026/09/13 15:16:10 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete17002026/09/13 15:16:10 OK 20260905000000_add_claims.sql (7.3ms)17012026/09/13 15:16:10 goose: successfully migrated database to version: 2026090500000017022026/09/13 15:16:10 INFO Completed upload id=117032026/09/13 15:16:10 WARN claim: cannot clear write deadline error="feature not supported"17042026/09/13 15:16:10 OK 1_commit_pending_closure.sql (2.85ms)17052026/09/13 15:16:10 OK 2_object_stats_trigger.sql (893.41µs)17062026/09/13 15:16:10 goose: up to current file version: 217072026/09/13 15:16:10 INFO Received uploads request method=POST path=/api/pending_closures17082026/09/13 15:16:10 INFO Received uploads request method=POST path=/api/pending_closures17092026/09/13 15:16:10 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo17102026/09/13 15:16:10 WARN Found objects in DB but missing from S3, will re-upload count=11711--- PASS: TestService_verifyS3Integrity (6.17s)1712=== CONT TestService_AuthMiddleware_MTLSBoundSubjects17132026/09/13 15:16:10 WARN claim: cannot clear write deadline error="feature not supported"1714--- PASS: TestClaim_StaleHeartbeatStolen (3.94s)1715=== CONT TestService_AuthMiddleware_MTLSProxyHeader17162026/09/13 15:16:10 INFO Received uploads request method=POST path=/api/pending_closures17172026/09/13 15:16:10 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)17182026/09/13 15:16:10 INFO Uploading xla1j5piszx2rbk44nhy0ci9z9m9l2vd-file1.txt (160B)17192026/09/13 15:16:10 WARN readiness check failed error="closed pool"1720--- PASS: TestService_readinessHandler (3.92s)1721=== CONT TestGCTaskStore_StartNew1722--- PASS: TestGCTaskStore_StartNew (0.00s)1723=== CONT TestGCTaskStore_GetEmpty1724--- PASS: TestGCTaskStore_GetEmpty (0.00s)1725=== CONT TestGCTaskStore_ConflictDifferentParams1726--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)1727=== CONT TestResolveDBConnectionString1728=== RUN TestResolveDBConnectionString/flag_wins1729=== PAUSE TestResolveDBConnectionString/flag_wins1730=== RUN TestResolveDBConnectionString/file_when_flag_empty1731=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1732=== RUN TestResolveDBConnectionString/missing_file_is_an_error1733=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1734=== RUN TestResolveDBConnectionString/PGHOST_allows_empty1735=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1736=== RUN TestResolveDBConnectionString/nothing_configured1737=== PAUSE TestResolveDBConnectionString/nothing_configured1738=== CONT TestGCMetrics17392026/09/13 15:16:10 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"17402026/09/13 15:16:10 WARN Failed to register uploaded object key=xla1j5piszx2rbk44nhy0ci9z9m9l2vd.ls error="server returned 404: 404 page not found\n"17412026/09/13 15:16:10 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign17422026/09/13 15:16:10 INFO Signed narinfos id=1 count=117432026/09/13 15:16:10 INFO Uploading 1 narinfos17442026/09/13 15:16:10 WARN Failed to register uploaded object key=xla1j5piszx2rbk44nhy0ci9z9m9l2vd.narinfo error="server returned 404: 404 page not found\n"17452026/09/13 15:16:10 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete1746=== NAME TestClientCADerivations1747 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features1748 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable1749 error: binary cache 's3://bucket38?endpoint=http://localhost:36317®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations2528514457/001/store'1750 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 117512026/09/13 15:16:10 INFO Completed upload id=117522026/09/13 15:16:10 INFO Upload complete. (127ms)1753--- PASS: TestClientCADerivations (4.20s)1754=== CONT TestGCTaskStore_DeduplicateSameParams1755--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)1756=== CONT TestGCBugBareHashReferences1757=== NAME TestNARDeduplicationMetadataUploadBug1758 metadata_upload_test.go:54: Retrieved narinfo from S3:1759 StorePath: /build/TestNARDeduplicationMetadataUploadBug3147550459/001/store/xla1j5piszx2rbk44nhy0ci9z9m9l2vd-file1.txt1760 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1761 Compression: zstd1762 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1763 NarSize: 1601764 References: 1765 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf17662026/09/13 15:16:10 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1767 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1768 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1769 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}17702026/09/13 15:16:10 WARN claim: cannot clear write deadline error="feature not supported"17712026-09-13 15:16:10.494 UTC [1508] ERROR: relation "goose_db_version" does not exist at character 3617722026-09-13 15:16:10.494 UTC [1508] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17732026/09/13 15:16:10 WARN claim: cannot clear write deadline error="feature not supported"1774--- PASS: TestClaim_FailWithoutKindReleases (3.96s)1775=== CONT TestIsValidCachePath/narinfo1776=== CONT TestIsValidCachePath/wrong_extension1777=== CONT TestIsValidCachePath/short_hash1778=== CONT TestIsValidCachePath/leading_slash1779=== CONT TestIsValidCachePath/empty1780=== CONT TestIsValidCachePath/log1781=== CONT TestIsValidCachePath/ls1782=== CONT TestIsValidCachePath/realisation1783=== CONT TestIsValidCachePath/nar_uncompressed1784=== CONT TestIsValidCachePath/random_path1785=== CONT TestIsValidCachePath/nar_bz21786=== CONT TestIsValidCachePath/nar_xz1787=== CONT TestIsValidCachePath/traversal_parent1788=== CONT TestIsValidCachePath/nar_zst1789=== CONT TestIsValidCachePath/index.html1790=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1791=== CONT TestIsValidCachePath/nix-cache-info1792=== CONT TestIsValidCachePath/traversal_in_middle1793=== CONT TestIsValidCachePath/invalid_char_u1794=== CONT TestIsValidCachePath/invalid_char_e1795=== CONT TestParseSingleRange/none1796=== CONT TestParseSingleRange/start_far_past_EOF1797=== CONT TestParseSingleRange/start_past_EOF1798=== CONT TestParseSingleRange/single_byte1799=== CONT TestParseSingleRange/suffix_exceeds_size1800--- PASS: TestIsValidCachePath (0.00s)1801 --- PASS: TestIsValidCachePath/narinfo (0.00s)1802 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1803 --- PASS: TestIsValidCachePath/short_hash (0.00s)1804 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1805 --- PASS: TestIsValidCachePath/empty (0.00s)1806 --- PASS: TestIsValidCachePath/log (0.00s)1807 --- PASS: TestIsValidCachePath/ls (0.00s)1808 --- PASS: TestIsValidCachePath/realisation (0.00s)1809 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1810 --- PASS: TestIsValidCachePath/random_path (0.00s)1811 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1812 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1813 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1814 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1815 --- PASS: TestIsValidCachePath/index.html (0.00s)1816 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1817 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1818 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1819 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1820 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1821=== CONT TestParseSingleRange/suffix1822=== CONT TestParseSingleRange/end_clamped_to_size1823=== CONT TestParseSingleRange/open-ended1824=== CONT TestParseSingleRange/closed1825=== CONT TestParseSingleRange/malformed_end_before_start1826=== CONT TestParseSingleRange/malformed_both_empty1827=== CONT TestParseSingleRange/malformed_no_dash1828=== CONT TestParseSingleRange/multi-range_ignored1829=== CONT TestParseSingleRange/unknown_unit1830=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1831--- PASS: TestParseSingleRange (0.00s)1832 --- PASS: TestParseSingleRange/none (0.00s)1833 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1834 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1835 --- PASS: TestParseSingleRange/single_byte (0.00s)1836 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1837 --- PASS: TestParseSingleRange/suffix (0.00s)1838 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1839 --- PASS: TestParseSingleRange/open-ended (0.00s)1840 --- PASS: TestParseSingleRange/closed (0.00s)1841 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1842 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1843 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1844 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1845 --- PASS: TestParseSingleRange/unknown_unit (0.00s)18462026/09/13 15:16:10 INFO Received uploads request method=POST path=/1847=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key18482026/09/13 15:16:10 INFO Received complete multipart upload request method=POST path=/1849=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal18502026/09/13 15:16:10 INFO Received uploads request method=POST path=/1851=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key18522026/09/13 15:16:10 INFO Received request for more parts method=POST path=/1853--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)1854 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1855 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1856 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1857 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1858=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure18592026/09/13 15:16:10 INFO Received uploads request method=POST path=/18602026/09/13 15:16:10 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=YTM4NDNmOWQtM2YyZC00Yzg5LTg4ZTEtOWZhMGU5ZGYwMDJjLjRmM2JlNDFmLWYzZjMtNGNkZS1iY2I0LTkxMzA2NDRmMmVlZHgxNzg5MzEyNTY4MTM4NzQ3NjU5 parts=1018612026/09/13 15:16:10 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete18622026-09-13 15:16:10.508 UTC [1509] ERROR: relation "goose_db_version" does not exist at character 3618632026-09-13 15:16:10.508 UTC [1509] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18642026/09/13 15:16:10 INFO Completed upload id=118652026/09/13 15:16:10 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000018662026/09/13 15:16:10 INFO Received uploads request method=POST path=/api/pending_closures1867=== NAME TestNARDeduplicationMetadataUploadBug1868 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug3147550459/001/store/4cy8w1y89sc0kycar4cbj5i1dgqnz4ay-file2.txt18692026/09/13 15:16:10 OK 20241026095416_initial_model.sql (19.72ms)1870--- PASS: TestService_healthCheckHandler (2.33s)1871=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts18722026/09/13 15:16:10 INFO Received request for more parts method=POST path=/18732026/09/13 15:16:10 INFO Starting cleanup of old closures method=DELETE path=/api/closures18742026/09/13 15:16:10 OK 20251210153512_drop_unused_gin_index.sql (3.28ms)18752026/09/13 15:16:10 OK 20241026095416_initial_model.sql (12.9ms)18762026/09/13 15:16:10 OK 20251218171726_add_pins.sql (3.7ms)18772026/09/13 15:16:10 OK 20251210153512_drop_unused_gin_index.sql (1.56ms)18782026-09-13 15:16:10.538 UTC [1528] ERROR: relation "goose_db_version" does not exist at character 3618792026-09-13 15:16:10.538 UTC [1528] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18802026/09/13 15:16:10 OK 20251218171726_add_pins.sql (7.96ms)18812026/09/13 15:16:10 OK 20260628120000_add_object_size_and_stats.sql (7.82ms)18822026/09/13 15:16:10 INFO Aborted multipart uploads count=018832026-09-13 15:16:10.546 UTC [1529] ERROR: relation "goose_db_version" does not exist at character 3618842026-09-13 15:16:10.546 UTC [1529] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18852026/09/13 15:16:10 OK 20260628120000_add_object_size_and_stats.sql (10.1ms)18862026/09/13 15:16:10 OK 20260905000000_add_claims.sql (9.24ms)18872026/09/13 15:16:10 goose: successfully migrated database to version: 2026090500000018882026/09/13 15:16:10 WARN claim: cannot clear write deadline error="feature not supported"18892026/09/13 15:16:10 OK 1_commit_pending_closure.sql (2.48ms)18902026/09/13 15:16:10 OK 2_object_stats_trigger.sql (2.48ms)18912026/09/13 15:16:10 goose: up to current file version: 218922026/09/13 15:16:10 OK 20260905000000_add_claims.sql (5.98ms)18932026/09/13 15:16:10 goose: successfully migrated database to version: 2026090500000018942026/09/13 15:16:10 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=018952026/09/13 15:16:10 OK 1_commit_pending_closure.sql (2.05ms)18962026/09/13 15:16:10 OK 2_object_stats_trigger.sql (1.68ms)18972026/09/13 15:16:10 goose: up to current file version: 218982026/09/13 15:16:10 WARN claim: cannot clear write deadline error="feature not supported"18992026/09/13 15:16:10 INFO Vacuumed table table=pending_closures19002026/09/13 15:16:10 OK 20241026095416_initial_model.sql (10.8ms)19012026/09/13 15:16:10 WARN claim: cannot clear write deadline error="feature not supported"19022026/09/13 15:16:10 INFO Vacuumed table table=pending_objects1903--- PASS: TestClaim_FailWakesWaitersButIsNotRemembered (1.76s)1904=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart19052026/09/13 15:16:10 OK 20251210153512_drop_unused_gin_index.sql (1.69ms)19062026/09/13 15:16:10 INFO Received complete multipart upload request method=POST path=/19072026/09/13 15:16:10 OK 20241026095416_initial_model.sql (14.42ms)19082026/09/13 15:16:10 INFO Vacuumed table table=multipart_uploads19092026/09/13 15:16:10 OK 20251210153512_drop_unused_gin_index.sql (2.02ms)19102026/09/13 15:16:10 OK 20251218171726_add_pins.sql (10.17ms)19112026/09/13 15:16:10 INFO Vacuumed table table=closures19122026/09/13 15:16:10 INFO Vacuumed table table=objects19132026/09/13 15:16:10 OK 20251218171726_add_pins.sql (4.07ms)19142026/09/13 15:16:10 OK 20260628120000_add_object_size_and_stats.sql (3.6ms)19152026/09/13 15:16:10 OK 20260905000000_add_claims.sql (4.38ms)19162026/09/13 15:16:10 goose: successfully migrated database to version: 2026090500000019172026/09/13 15:16:10 OK 20260628120000_add_object_size_and_stats.sql (4.97ms)19182026/09/13 15:16:10 OK 1_commit_pending_closure.sql (2.26ms)19192026/09/13 15:16:10 OK 20260905000000_add_claims.sql (3.53ms)19202026/09/13 15:16:10 goose: successfully migrated database to version: 2026090500000019212026/09/13 15:16:10 WARN claim: cannot clear write deadline error="feature not supported"19222026/09/13 15:16:10 OK 1_commit_pending_closure.sql (1.94ms)19232026/09/13 15:16:10 OK 2_object_stats_trigger.sql (891.67µs)19242026/09/13 15:16:10 goose: up to current file version: 219252026/09/13 15:16:10 OK 2_object_stats_trigger.sql (1.18ms)19262026/09/13 15:16:10 goose: up to current file version: 219272026/09/13 15:16:10 WARN claim: cannot clear write deadline error="feature not supported"19282026/09/13 15:16:10 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"19292026/09/13 15:16:10 WARN claim: cannot clear write deadline error="feature not supported"1930--- PASS: TestClaim_TooManyStreams (1.18s)1931=== CONT TestServerTLSConfig/no_client_CA1932=== CONT TestServerTLSConfig/missing_CA_file1933=== CONT TestServerTLSConfig/not_a_PEM_file1934--- PASS: TestServerTLSConfig (0.00s)1935 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1936 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1937 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)19382026/09/13 15:16:10 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001939=== CONT TestClientErrorHandling/InvalidStorePath1940--- PASS: TestService_createPendingClosureHandler (6.03s)1941=== CONT TestClientErrorHandling/InvalidAuthToken1942=== CONT TestClientErrorHandling/ServerNotAvailable19432026/09/13 15:16:10 INFO Received uploads request method=POST path=/api/pending_closures19442026/09/13 15:16:10 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)19452026/09/13 15:16:10 WARN Failed to register uploaded object key=4cy8w1y89sc0kycar4cbj5i1dgqnz4ay.ls error="server returned 404: 404 page not found\n"19462026/09/13 15:16:10 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign19472026/09/13 15:16:10 INFO Signed narinfos id=2 count=119482026/09/13 15:16:10 INFO Uploading 1 narinfos19492026/09/13 15:16:10 WARN Failed to register uploaded object key=4cy8w1y89sc0kycar4cbj5i1dgqnz4ay.narinfo error="server returned 404: 404 page not found\n"19502026/09/13 15:16:10 INFO Received uploads request method=POST path=/api/pending_closures19512026/09/13 15:16:10 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete19522026/09/13 15:16:10 INFO Completed upload id=219532026/09/13 15:16:10 INFO Upload complete. (122ms)1954=== NAME TestNARDeduplicationMetadataUploadBug1955 metadata_upload_test.go:76: Retrieved narinfo from S3:1956 StorePath: /build/TestNARDeduplicationMetadataUploadBug3147550459/001/store/4cy8w1y89sc0kycar4cbj5i1dgqnz4ay-file2.txt1957 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1958 Compression: zstd1959 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1960 NarSize: 1601961 References: 1962 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1963 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1964 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1965 {"version":1,"root":{"type":"regular","size":44}}1966--- PASS: TestNARDeduplicationMetadataUploadBug (4.40s)1967=== CONT TestIsValidUploadKey/narinfo1968=== CONT TestIsValidUploadKey/realisation1969=== CONT TestIsValidUploadKey/build_log_equals1970=== CONT TestIsValidUploadKey/build_log_question_mark1971=== CONT TestIsValidUploadKey/build_log_plus_in_name1972=== CONT TestIsValidUploadKey/build_log_home-manager_file1973=== CONT TestIsValidUploadKey/realisation_plus_in_output1974=== CONT TestIsValidUploadKey/build_log1975=== CONT TestIsValidUploadKey/nix-cache-info1976=== CONT TestIsValidUploadKey/listing1977=== CONT TestIsValidUploadKey/nar_xz1978=== CONT TestIsValidUploadKey/nar_zst1979=== CONT TestIsValidUploadKey/nar_plain1980=== CONT TestIsValidUploadKey/traversal1981=== CONT TestIsValidUploadKey/empty_key1982=== CONT TestIsValidUploadKey/traversal_nar1983=== CONT TestIsValidUploadKey/unknown_type1984=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1985=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1986=== CONT TestIsValidUploadKey/absolute1987=== CONT TestIsValidUploadKey/index.html1988=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1989=== CONT TestCacheConfigHandler/full_config,_no_issuer1990=== CONT TestCacheConfigHandler/no_signing_keys1991--- PASS: TestIsValidUploadKey (0.00s)1992 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1993 --- PASS: TestIsValidUploadKey/realisation (0.00s)1994 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1995 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1996 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1997 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1998 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1999 --- PASS: TestIsValidUploadKey/build_log (0.00s)2000 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)2001 --- PASS: TestIsValidUploadKey/listing (0.00s)2002 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)2003 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)2004 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)2005 --- PASS: TestIsValidUploadKey/traversal (0.00s)2006 --- PASS: TestIsValidUploadKey/empty_key (0.00s)2007 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)2008 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)2009 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)2010 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)2011 --- PASS: TestIsValidUploadKey/absolute (0.00s)2012 --- PASS: TestIsValidUploadKey/index.html (0.00s)2013 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)2014=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator2015=== CONT TestCacheConfigHandler/no_cache_url_configured2016=== CONT TestProxyWriteTimeout/narinfo2017=== CONT TestProxyWriteTimeout/10_GiB_nar2018=== CONT TestProxyWriteTimeout/unknown_size2019=== CONT TestProxyWriteTimeout/1_GiB_nar2020=== CONT TestResolveDBConnectionString/flag_wins2021=== CONT TestResolveDBConnectionString/PGHOST_allows_empty2022=== CONT TestResolveDBConnectionString/missing_file_is_an_error2023--- PASS: TestProxyWriteTimeout (0.00s)2024 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)2025 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)2026 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)2027 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)2028=== CONT TestResolveDBConnectionString/file_when_flag_empty2029--- PASS: TestCacheConfigHandler (0.00s)2030 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)2031 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)2032 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)2033 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)2034=== CONT TestResolveDBConnectionString/nothing_configured2035--- PASS: TestResolveDBConnectionString (0.00s)2036 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)2037 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)2038 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)2039 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)2040 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)20412026-09-13 15:16:10.719 UTC [1610] ERROR: relation "goose_db_version" does not exist at character 3620422026-09-13 15:16:10.719 UTC [1610] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC20432026-09-13 15:16:10.722 UTC [1609] ERROR: relation "goose_db_version" does not exist at character 3620442026-09-13 15:16:10.722 UTC [1609] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC20452026/09/13 15:16:10 OK 20241026095416_initial_model.sql (10.4ms)20462026/09/13 15:16:10 OK 20241026095416_initial_model.sql (9.98ms)20472026/09/13 15:16:10 OK 20251210153512_drop_unused_gin_index.sql (2.41ms)20482026/09/13 15:16:10 OK 20251210153512_drop_unused_gin_index.sql (6.99ms)20492026/09/13 15:16:10 OK 20251218171726_add_pins.sql (7.98ms)20502026/09/13 15:16:10 OK 20251218171726_add_pins.sql (4.9ms)20512026/09/13 15:16:10 OK 20260628120000_add_object_size_and_stats.sql (3.36ms)20522026/09/13 15:16:10 OK 20260905000000_add_claims.sql (4.11ms)20532026/09/13 15:16:10 goose: successfully migrated database to version: 2026090500000020542026/09/13 15:16:10 OK 20260628120000_add_object_size_and_stats.sql (4.8ms)20552026/09/13 15:16:10 OK 1_commit_pending_closure.sql (2.04ms)20562026/09/13 15:16:10 OK 2_object_stats_trigger.sql (971.01µs)20572026/09/13 15:16:10 goose: up to current file version: 220582026/09/13 15:16:10 OK 20260905000000_add_claims.sql (6.9ms)20592026/09/13 15:16:10 goose: successfully migrated database to version: 2026090500000020602026/09/13 15:16:10 OK 1_commit_pending_closure.sql (2.17ms)20612026/09/13 15:16:10 OK 2_object_stats_trigger.sql (896.35µs)20622026/09/13 15:16:10 goose: up to current file version: 220632026/09/13 15:16:10 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-config20642026/09/13 15:16:10 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=196.225141ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20652026/09/13 15:16:10 INFO Received complete multipart upload request method=POST path=/api/multipart/complete20662026/09/13 15:16:10 INFO Completed multipart upload object_key=nar/0000000000000000000000000000001600000000000000000000.nar.zst upload_id=YTM4NDNmOWQtM2YyZC00Yzg5LTg4ZTEtOWZhMGU5ZGYwMDJjLjI3NTBlZGU0LTBkODItNGJhZC1iYWI2LWJmOWYzN2E4NDM3ZXgxNzg5MzEyNTcwMzczNTk0MjQ0 parts=1020672026/09/13 15:16:10 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign20682026/09/13 15:16:10 INFO Signed narinfos id=1 count=120692026/09/13 15:16:10 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete20702026/09/13 15:16:10 INFO Completed upload id=12071--- PASS: TestClaim_TwoInstances (4.58s)20722026/09/13 15:16:11 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=395.480421ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20732026/09/13 15:16:11 WARN claim: cannot clear write deadline error="feature not supported"20742026/09/13 15:16:11 INFO Received complete multipart upload request method=POST path=/api/multipart/complete20752026/09/13 15:16:11 INFO Completed multipart upload object_key=nar/0000000000000000000000000000001100000000000000000000.nar.zst upload_id=YTM4NDNmOWQtM2YyZC00Yzg5LTg4ZTEtOWZhMGU5ZGYwMDJjLmRiYzI2NDNhLTM1MDUtNGVkYy1hMWJhLWJhYjlhNTA5ZWEzYngxNzg5MzEyNTcwNjkxODc2MzQ0 parts=1020762026/09/13 15:16:11 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete20772026/09/13 15:16:11 INFO Completed upload id=120782026/09/13 15:16:11 WARN claim: cannot clear write deadline error="feature not supported"20792026/09/13 15:16:11 WARN claim: cannot clear write deadline error="feature not supported"2080--- PASS: TestClaim_GCMarkedOutputCountsAsAbsent (1.63s)20812026/09/13 15:16:11 WARN claim: cannot clear write deadline error="feature not supported"20822026/09/13 15:16:11 WARN claim: cannot clear write deadline error="feature not supported"20832026/09/13 15:16:11 WARN claim: cannot clear write deadline error="feature not supported"20842026/09/13 15:16:11 INFO Received uploads request method=POST path=/api/pending_closures2085--- PASS: TestCacheStatsHandler (1.69s)2086--- PASS: TestService_ReadScope_PublicByDefault (1.68s)2087=== RUN TestService_RequireScope_OIDC/builder_may_write2088=== PAUSE TestService_RequireScope_OIDC/builder_may_write2089=== RUN TestService_RequireScope_OIDC/builder_may_not_admin2090=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin2091=== RUN TestService_RequireScope_OIDC/ops_may_admin2092=== PAUSE TestService_RequireScope_OIDC/ops_may_admin2093=== RUN TestService_RequireScope_OIDC/ops_may_not_write2094=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write2095=== RUN TestService_RequireScope_OIDC/reader_may_not_write2096=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write2097=== RUN TestService_RequireScope_OIDC/static_token_may_admin2098=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin2099=== RUN TestService_RequireScope_OIDC/static_token_may_write2100=== PAUSE TestService_RequireScope_OIDC/static_token_may_write2101=== RUN TestService_RequireScope_OIDC/reader_may_read2102=== PAUSE TestService_RequireScope_OIDC/reader_may_read2103=== RUN TestService_RequireScope_OIDC/writer_implies_read2104=== PAUSE TestService_RequireScope_OIDC/writer_implies_read2105=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read2106=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read2107=== CONT TestService_RequireScope_OIDC/builder_may_write2108=== CONT TestService_RequireScope_OIDC/static_token_may_admin2109=== CONT TestService_RequireScope_OIDC/writer_implies_read2110=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read2111=== CONT TestService_RequireScope_OIDC/ops_may_not_write2112=== CONT TestService_RequireScope_OIDC/reader_may_read2113=== CONT TestService_RequireScope_OIDC/reader_may_not_write2114=== CONT TestService_RequireScope_OIDC/static_token_may_write2115=== CONT TestService_RequireScope_OIDC/builder_may_not_admin2116=== CONT TestService_RequireScope_OIDC/ops_may_admin21172026/09/13 15:16:11 INFO OIDC auth successful provider=test scopes=[admin]21182026/09/13 15:16:11 INFO OIDC auth successful provider=test scopes=[write]21192026/09/13 15:16:11 INFO OIDC auth successful provider=test scopes=[write]21202026/09/13 15:16:11 INFO OIDC auth successful provider=test scopes=[read]21212026/09/13 15:16:11 INFO OIDC auth successful provider=test scopes=[read]21222026/09/13 15:16:11 INFO OIDC auth successful provider=test scopes=[write]21232026/09/13 15:16:11 INFO OIDC auth successful provider=test scopes=[admin]2124--- PASS: TestService_RequireScope_OIDC (1.74s)2125 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)2126 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)2127 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)2128 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)2129 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)2130 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)2131 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)2132 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)2133 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)2134 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)21352026/09/13 15:16:11 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=736.5118ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2136--- PASS: TestClaim_StreamsThroughServer (5.46s)2137=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token2138=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token2139=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected2140=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected2141=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected2142=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected2143=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2144=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2145=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token2146=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected2147=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2148=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected21492026/09/13 15:16:11 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]21502026/09/13 15:16:11 WARN Authentication failed token_preview=eyJhbGciOi...nj1wxv-zQw token_length=702 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]21512026/09/13 15:16:11 INFO OIDC auth successful provider=test scopes=[write]2152--- PASS: TestService_AuthMiddleware_OIDC (2.07s)2153 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)2154 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)2155 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.01s)2156 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.01s)2157--- PASS: TestService_ReadAuthMiddleware (1.53s)2158=== NAME TestOrphanedObjectsGCStressTest2159 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains2160 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion2161--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (1.44s)21622026/09/13 15:16:11 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"21632026/09/13 15:16:11 WARN mTLS auth: bound subjects configured but subject DN unavailable21642026/09/13 15:16:11 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"2165--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (1.47s)21662026/09/13 15:16:11 INFO Received complete multipart upload request method=POST path=/api/multipart/complete2167--- PASS: TestUploadHandlersRejectOversizedBody (0.20s)2168 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.12s)2169 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.12s)2170 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (1.41s)21712026/09/13 15:16:11 INFO Completed multipart upload object_key=nar/0000000000000000000000000000001700000000000000000000.nar.zst upload_id=YTM4NDNmOWQtM2YyZC00Yzg5LTg4ZTEtOWZhMGU5ZGYwMDJjLmI2NWQ1NzM1LWM3ZGItNGRiZi1hYTcwLTkzYzAyMmFhNTAwY3gxNzg5MzEyNTcwMzIwNDc2NzA2 parts=1021722026/09/13 15:16:11 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete21732026/09/13 15:16:11 INFO Completed upload id=121742026/09/13 15:16:11 WARN claim: cannot clear write deadline error="feature not supported"21752026/09/13 15:16:11 INFO Aborted multipart uploads count=021762026/09/13 15:16:11 WARN Force mode enabled - objects will be deleted immediately without grace period21772026/09/13 15:16:11 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=021782026/09/13 15:16:11 INFO Vacuumed table table=pending_closures21792026/09/13 15:16:11 INFO Vacuumed table table=pending_objects21802026/09/13 15:16:11 INFO Vacuumed table table=multipart_uploads21812026/09/13 15:16:11 INFO Vacuumed table table=closures21822026/09/13 15:16:11 INFO Vacuumed table table=objects2183--- PASS: TestClaim_InputsTouched (5.61s)21842026/09/13 15:16:12 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.481816304s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21852026/09/13 15:16:12 INFO Garbage collection progress phase=cleanup_orphan_objects failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=0 objects_failed=021862026/09/13 15:16:12 INFO Garbage collection progress phase=cleanup_orphan_objects failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=0 objects_failed=021872026/09/13 15:16:12 INFO Received complete multipart upload request method=POST path=/api/multipart/complete2188=== NAME TestOrphanedObjectsGCStressTest2189 orphaned_objects_gc_test.go:509: Stress test completed successfully:2190 orphaned_objects_gc_test.go:510: - Active objects preserved: 202191 orphaned_objects_gc_test.go:511: - Objects deleted: 2102192 orphaned_objects_gc_test.go:512: - Total GC'd: 2102193--- PASS: TestOrphanedObjectsGCStressTest (7.66s)21942026/09/13 15:16:12 INFO Completed multipart upload object_key=nar/0000000000000000000000000000001000000000000000000000.nar.zst upload_id=YTM4NDNmOWQtM2YyZC00Yzg5LTg4ZTEtOWZhMGU5ZGYwMDJjLjY1MGY2ODNjLTgyODQtNGY0My1hM2ZlLTgxN2RkNzgzNTk1M3gxNzg5MzEyNTcxMzU1MDk1NjA0 parts=1021952026/09/13 15:16:12 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign21962026/09/13 15:16:12 INFO Signed narinfos id=1 count=121972026/09/13 15:16:12 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete21982026/09/13 15:16:12 INFO Received uploads request method=POST path=/api/pending_closures21992026/09/13 15:16:12 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign22002026/09/13 15:16:12 INFO Signed narinfos id=2 count=122012026/09/13 15:16:12 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete22022026/09/13 15:16:12 INFO Completed upload id=222032026/09/13 15:16:12 WARN claim: cannot clear write deadline error="feature not supported"2204--- PASS: TestClaim_BuildWaitComplete (2.75s)2205--- PASS: TestClaim_HolderDisconnectKeepsClaim (3.69s)22062026/09/13 15:16:13 INFO Aborted multipart uploads count=022072026/09/13 15:16:13 WARN Force mode enabled - objects will be deleted immediately without grace period22082026/09/13 15:16:13 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=022092026/09/13 15:16:13 INFO Vacuumed table table=pending_closures22102026/09/13 15:16:13 INFO Vacuumed table table=pending_objects22112026/09/13 15:16:13 INFO Vacuumed table table=multipart_uploads22122026/09/13 15:16:13 INFO Vacuumed table table=closures22132026/09/13 15:16:13 INFO Vacuumed table table=objects2214--- PASS: TestGCMetrics (2.77s)22152026/09/13 15:16:13 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"2216--- PASS: TestGCBugBareHashReferences (2.92s)22172026/09/13 15:16:13 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"22182026/09/13 15:16:13 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"22192026/09/13 15:16:13 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_closures22202026/09/13 15:16:13 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=217.631317ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22212026/09/13 15:16:14 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=370.111991ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22222026/09/13 15:16:14 INFO Garbage collection progress phase=cleanup_orphan_objects failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=1000 objects_failed=022232026/09/13 15:16:14 INFO Garbage collection progress phase=cleanup_orphan_objects failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=1000 objects_failed=022242026/09/13 15:16:14 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=773.332078ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22252026/09/13 15:16:14 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=022262026/09/13 15:16:14 INFO Vacuumed table table=pending_closures22272026/09/13 15:16:14 INFO Vacuumed table table=pending_objects22282026/09/13 15:16:14 INFO Vacuumed table table=multipart_uploads22292026/09/13 15:16:15 INFO Vacuumed table table=closures22302026/09/13 15:16:15 INFO Vacuumed table table=objects22312026/09/13 15:16:15 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=3 objects-deleted-after-grace-period=2001 objects-failed-to-delete=022322026/09/13 15:16:15 INFO Vacuumed table table=pending_closures22332026/09/13 15:16:15 INFO Vacuumed table table=pending_objects22342026/09/13 15:16:15 INFO Vacuumed table table=multipart_uploads22352026/09/13 15:16:15 INFO Vacuumed table table=closures22362026/09/13 15:16:15 INFO Vacuumed table table=objects22372026/09/13 15:16:15 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.564219999s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22382026/09/13 15:16:16 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=022392026/09/13 15:16:16 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=02240=== NAME TestPinProtectsFromGC2241 client_integration_test.go:711: Pin successfully protected closure from garbage collection2242=== NAME TestClientIntegration2243 client_integration_test.go:304: Objects in database after GC:2244 client_integration_test.go:304: Successfully deleted all objects with GC --force2245--- PASS: TestPinProtectsFromGC (11.43s)2246--- PASS: TestClientIntegration (10.17s)2247--- PASS: TestClientErrorHandling (0.00s)2248 --- PASS: TestClientErrorHandling/InvalidStorePath (2.62s)2249 --- PASS: TestClientErrorHandling/InvalidAuthToken (2.77s)2250 --- PASS: TestClientErrorHandling/ServerNotAvailable (6.13s)2251PASS22522026-09-13 15:16:17.091 UTC [127] LOG: received smart shutdown request22532026-09-13 15:16:17.096 UTC [127] LOG: background worker "logical replication launcher" (PID 137) exited with exit code 122542026-09-13 15:16:17.110 UTC [132] LOG: shutting down22552026-09-13 15:16:17.111 UTC [132] LOG: checkpoint starting: shutdown immediate22562026-09-13 15:16:17.951 UTC [132] LOG: checkpoint complete: wrote 11776 buffers (71.9%), wrote 3 SLRU buffers; 0 WAL file(s) added, 0 removed, 17 recycled; write=0.227 s, sync=0.606 s, total=0.841 s; sync files=21000, longest=0.010 s, average=0.001 s; distance=282890 kB, estimate=282890 kB; lsn=0/12BA8720, redo lsn=0/12BA872022572026-09-13 15:16:18.048 UTC [127] LOG: database system is shut down2258Running OIDC tests...2259=== RUN TestGlobMatch2260=== PAUSE TestGlobMatch2261=== RUN TestAudienceForIssuer2262=== PAUSE TestAudienceForIssuer2263=== RUN TestValidateToken_ValidToken2264=== PAUSE TestValidateToken_ValidToken2265=== RUN TestValidateToken_WrongAudience2266=== PAUSE TestValidateToken_WrongAudience2267=== RUN TestValidateToken_Expired2268=== PAUSE TestValidateToken_Expired2269=== RUN TestValidateToken_BoundClaimsMismatch2270=== PAUSE TestValidateToken_BoundClaimsMismatch2271=== RUN TestValidateToken_BoundSubjectMismatch2272=== PAUSE TestValidateToken_BoundSubjectMismatch2273=== RUN TestValidateToken_MultipleProviders2274=== PAUSE TestValidateToken_MultipleProviders2275=== RUN TestValidateToken_NoMatchingProvider2276=== PAUSE TestValidateToken_NoMatchingProvider2277=== RUN TestValidateToken_KubernetesServiceAccount2278=== PAUSE TestValidateToken_KubernetesServiceAccount2279=== RUN TestNewValidator_KubernetesRequiresCA2280=== PAUSE TestNewValidator_KubernetesRequiresCA2281=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2282=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2283=== RUN TestScopes_LegacyProviderDefaultsToWrite2284=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2285=== RUN TestScopes_Rules2286=== PAUSE TestScopes_Rules2287=== RUN TestScopes_ConfigValidation2288=== PAUSE TestScopes_ConfigValidation2289=== CONT TestGlobMatch2290=== CONT TestScopes_LegacyProviderDefaultsToWrite2291=== CONT TestValidateToken_NoMatchingProvider2292=== CONT TestNewValidator_KubernetesRequiresCA2293=== RUN TestGlobMatch/foo_foo2294=== PAUSE TestGlobMatch/foo_foo2295=== RUN TestGlobMatch/foo_bar2296=== PAUSE TestGlobMatch/foo_bar2297=== RUN TestGlobMatch/*_2298=== PAUSE TestGlobMatch/*_2299=== RUN TestGlobMatch/*_anything2300=== PAUSE TestGlobMatch/*_anything2301=== RUN TestGlobMatch/foo*_foo2302=== PAUSE TestGlobMatch/foo*_foo2303=== RUN TestGlobMatch/foo*_foobar2304=== PAUSE TestGlobMatch/foo*_foobar2305=== RUN TestGlobMatch/foo*_bar2306=== PAUSE TestGlobMatch/foo*_bar2307=== RUN TestGlobMatch/*bar_bar2308=== CONT TestValidateToken_MultipleProviders2309=== CONT TestValidateToken_BoundSubjectMismatch2310=== CONT TestValidateToken_BoundClaimsMismatch2311=== CONT TestValidateToken_Expired2312=== CONT TestValidateToken_WrongAudience2313=== CONT TestValidateToken_ValidToken2314=== CONT TestAudienceForIssuer2315--- PASS: TestAudienceForIssuer (0.00s)2316=== CONT TestScopes_ConfigValidation2317=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2318=== CONT TestValidateToken_KubernetesServiceAccount2319=== CONT TestScopes_Rules2320=== PAUSE TestGlobMatch/*bar_bar2321=== RUN TestGlobMatch/*bar_foobar2322=== PAUSE TestGlobMatch/*bar_foobar2323=== RUN TestGlobMatch/*bar_foo2324=== PAUSE TestGlobMatch/*bar_foo2325=== RUN TestGlobMatch/foo*bar_foobar2326=== PAUSE TestGlobMatch/foo*bar_foobar2327=== RUN TestGlobMatch/foo*bar_foo123bar2328=== PAUSE TestGlobMatch/foo*bar_foo123bar2329=== RUN TestGlobMatch/foo*bar_foobarbaz2330=== PAUSE TestGlobMatch/foo*bar_foobarbaz2331=== RUN TestGlobMatch/*/*_foo/bar2332=== PAUSE TestGlobMatch/*/*_foo/bar2333=== RUN TestGlobMatch/*/*_foo2334=== PAUSE TestGlobMatch/*/*_foo2335=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2336=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2337=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02338=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02339=== RUN TestGlobMatch/refs/*/main_refs/heads/main2340=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2341=== RUN TestGlobMatch/fo?_foo2342=== PAUSE TestGlobMatch/fo?_foo2343=== RUN TestGlobMatch/fo?_fo2344=== PAUSE TestGlobMatch/fo?_fo2345=== RUN TestGlobMatch/fo?_fooo2346=== PAUSE TestGlobMatch/fo?_fooo2347=== RUN TestGlobMatch/?oo_foo2348=== PAUSE TestGlobMatch/?oo_foo2349=== RUN TestGlobMatch/?oo_boo2350=== PAUSE TestGlobMatch/?oo_boo2351=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2352=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2353=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2354=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2355=== CONT TestGlobMatch/foo_foo2356=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2357=== CONT TestGlobMatch/foo*_bar2358=== CONT TestGlobMatch/foo*bar_foobarbaz2359=== CONT TestGlobMatch/fo?_fo2360=== CONT TestGlobMatch/fo?_fooo2361=== CONT TestGlobMatch/*_anything2362=== CONT TestGlobMatch/foo*_foobar2363=== CONT TestGlobMatch/*bar_bar2364=== CONT TestGlobMatch/*/*_foo2365=== CONT TestGlobMatch/foo*bar_foobar2366=== CONT TestGlobMatch/?oo_boo2367=== CONT TestGlobMatch/foo*_foo2368=== CONT TestGlobMatch/*_2369=== CONT TestGlobMatch/*/*_foo/bar2370=== CONT TestGlobMatch/*bar_foobar2371=== CONT TestGlobMatch/fo?_foo2372=== CONT TestGlobMatch/*bar_foo2373=== CONT TestGlobMatch/?oo_foo2374=== CONT TestGlobMatch/foo*bar_foo123bar2375=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2376=== CONT TestGlobMatch/refs/*/main_refs/heads/main2377=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02378=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2379=== CONT TestGlobMatch/foo_bar2380--- PASS: TestScopes_ConfigValidation (0.01s)2381--- PASS: TestGlobMatch (0.01s)2382 --- PASS: TestGlobMatch/foo_foo (0.00s)2383 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2384 --- PASS: TestGlobMatch/foo*_bar (0.00s)2385 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2386 --- PASS: TestGlobMatch/fo?_fo (0.00s)2387 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2388 --- PASS: TestGlobMatch/*_anything (0.00s)2389 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2390 --- PASS: TestGlobMatch/*bar_bar (0.00s)2391 --- PASS: TestGlobMatch/*/*_foo (0.00s)2392 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2393 --- PASS: TestGlobMatch/?oo_boo (0.00s)2394 --- PASS: TestGlobMatch/foo*_foo (0.00s)2395 --- PASS: TestGlobMatch/*_ (0.00s)2396 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2397 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2398 --- PASS: TestGlobMatch/fo?_foo (0.00s)2399 --- PASS: TestGlobMatch/*bar_foo (0.00s)2400 --- PASS: TestGlobMatch/?oo_foo (0.00s)2401 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2402 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2403 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2404 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2405 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2406 --- PASS: TestGlobMatch/foo_bar (0.00s)24072026/09/13 15:16:19 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:37541/oidc24082026/09/13 15:16:19 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:35499/oidc24092026/09/13 15:16:19 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:46011/oidc24102026/09/13 15:16:19 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:37979/oidc24112026/09/13 15:16:19 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:34325/oidc24122026/09/13 15:16:19 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:35319/oidc24132026/09/13 15:16:19 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:43453/oidc24142026/09/13 15:16:19 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:40409/oidc24152026/09/13 15:16:19 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:35867/oidc24162026/09/13 15:16:19 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:36445/oidc24172026/09/13 15:16:19 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC1232418--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.01s)2419--- PASS: TestValidateToken_BoundClaimsMismatch (0.01s)2420--- PASS: TestValidateToken_BoundSubjectMismatch (0.01s)2421--- PASS: TestValidateToken_MultipleProviders (0.01s)2422--- PASS: TestValidateToken_ValidToken (0.01s)2423--- PASS: TestValidateToken_WrongAudience (0.01s)2424--- PASS: TestValidateToken_Expired (0.01s)24252026/09/13 15:16:19 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:452232426--- PASS: TestValidateToken_NoMatchingProvider (0.02s)2427--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.02s)24282026/09/13 15:16:19 http: TLS handshake error from 127.0.0.1:38646: remote error: tls: bad certificate2429--- PASS: TestNewValidator_KubernetesRequiresCA (0.02s)2430--- PASS: TestValidateToken_KubernetesServiceAccount (0.02s)2431--- PASS: TestScopes_Rules (0.02s)2432PASS2433Running hook tests...2434=== RUN TestSendPathsEmpty2435=== PAUSE TestSendPathsEmpty2436=== RUN TestQueueEnqueueAndFetch2437=== PAUSE TestQueueEnqueueAndFetch2438=== RUN TestQueueDeduplication2439=== PAUSE TestQueueDeduplication2440=== RUN TestQueueRemove2441=== PAUSE TestQueueRemove2442=== RUN TestQueueFetchBatchLimit2443=== PAUSE TestQueueFetchBatchLimit2444=== RUN TestQueueRetryMovesToBack2445=== PAUSE TestQueueRetryMovesToBack2446=== RUN TestQueueFetchRemoveLifecycle2447=== PAUSE TestQueueFetchRemoveLifecycle2448=== RUN TestQueueConcurrentWriters2449=== PAUSE TestQueueConcurrentWriters2450=== RUN TestQueueRemoveLargeClosure2451=== PAUSE TestQueueRemoveLargeClosure2452=== RUN TestServerClientIntegration2453=== PAUSE TestServerClientIntegration2454=== RUN TestServerQueueError2455=== PAUSE TestServerQueueError2456=== RUN TestGetListenerSocketActivation2457 server_test.go:210: === RUN TestGetListenerSocketActivation2458 --- PASS: TestGetListenerSocketActivation (0.00s)2459 PASS2460 2461--- PASS: TestGetListenerSocketActivation (0.01s)2462=== RUN TestDrainIsolatesPoisonPath2463=== PAUSE TestDrainIsolatesPoisonPath2464=== RUN TestRunNotBlockedByPoisonHead2465=== PAUSE TestRunNotBlockedByPoisonHead2466=== RUN TestDrainGivesUpWhenServerDown2467=== PAUSE TestDrainGivesUpWhenServerDown2468=== RUN TestFailedPathPrunedByLaterClosure2469=== PAUSE TestFailedPathPrunedByLaterClosure2470=== RUN TestWorkerUploadsAndRemoves2471=== PAUSE TestWorkerUploadsAndRemoves2472=== RUN TestWorkerSkipsGCdPaths2473=== PAUSE TestWorkerSkipsGCdPaths2474=== RUN TestWorkerPrunesClosureDeps2475=== PAUSE TestWorkerPrunesClosureDeps2476=== RUN TestDrainTimeout2477=== PAUSE TestDrainTimeout2478=== CONT TestSendPathsEmpty2479=== CONT TestRunNotBlockedByPoisonHead2480=== CONT TestQueueFetchRemoveLifecycle2481=== CONT TestWorkerSkipsGCdPaths2482=== CONT TestQueueRetryMovesToBack2483=== CONT TestQueueFetchBatchLimit2484=== CONT TestQueueRemove2485=== CONT TestQueueDeduplication2486=== CONT TestQueueEnqueueAndFetch2487=== CONT TestServerClientIntegration2488=== CONT TestDrainIsolatesPoisonPath2489=== CONT TestServerQueueError2490=== CONT TestWorkerPrunesClosureDeps2491=== CONT TestFailedPathPrunedByLaterClosure2492=== CONT TestWorkerUploadsAndRemoves2493=== CONT TestDrainGivesUpWhenServerDown2494=== CONT TestQueueRemoveLargeClosure2495=== CONT TestQueueConcurrentWriters2496=== CONT TestDrainTimeout24972026/09/13 15:16:19 ERROR Failed to queue paths error="permission denied" count=12498--- PASS: TestSendPathsEmpty (0.00s)2499--- PASS: TestServerClientIntegration (0.00s)2500--- PASS: TestServerQueueError (0.00s)2501--- PASS: TestQueueFetchBatchLimit (0.01s)25022026/09/13 15:16:19 INFO Upload queue status pending=325032026/09/13 15:16:19 INFO Upload queue status pending=225042026/09/13 15:16:19 INFO Uploading batch count=125052026/09/13 15:16:19 ERROR Upload failed error="upload failed" count=125062026/09/13 15:16:19 INFO Uploading batch count=12507--- PASS: TestQueueEnqueueAndFetch (0.01s)25082026/09/13 15:16:19 ERROR Upload failed error="upload failed" count=125092026/09/13 15:16:19 INFO Uploading batch count=225102026/09/13 15:16:19 INFO Uploading batch count=225112026/09/13 15:16:19 INFO Uploading batch count=425122026/09/13 15:16:19 ERROR Upload failed error="upload failed" count=42513--- PASS: TestQueueDeduplication (0.02s)25142026/09/13 15:16:19 INFO Upload queue status pending=225152026/09/13 15:16:19 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainIsolatesPoisonPath2333958820/002/bbb25162026/09/13 15:16:19 INFO Uploading batch count=125172026/09/13 15:16:19 INFO Upload queue status pending=22518--- PASS: TestQueueRetryMovesToBack (0.02s)25192026/09/13 15:16:19 INFO Uploading batch count=125202026/09/13 15:16:19 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerSkipsGCdPaths365263846/002/nonexistent25212026/09/13 15:16:19 INFO Uploading batch count=225222026/09/13 15:16:19 ERROR Upload failed error="upload failed" count=225232026/09/13 15:16:19 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown624446124/002/a2524--- PASS: TestQueueRemove (0.02s)25252026/09/13 15:16:19 INFO Uploading batch count=125262026/09/13 15:16:19 INFO Uploading batch count=125272026/09/13 15:16:19 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown624446124/002/b2528--- PASS: TestQueueFetchRemoveLifecycle (0.02s)25292026/09/13 15:16:19 INFO Uploading batch count=125302026/09/13 15:16:19 ERROR Upload failed error="upload failed" count=125312026/09/13 15:16:19 INFO Uploading batch count=225322026/09/13 15:16:19 ERROR Upload failed error="upload failed" count=225332026/09/13 15:16:19 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown624446124/002/c25342026/09/13 15:16:19 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown624446124/002/d25352026/09/13 15:16:19 INFO Uploading batch count=125362026/09/13 15:16:19 ERROR Upload failed error="upload failed" count=12537--- PASS: TestFailedPathPrunedByLaterClosure (0.02s)25382026/09/13 15:16:19 INFO Uploading batch count=225392026/09/13 15:16:19 ERROR Upload failed error="upload failed" count=225402026/09/13 15:16:19 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown624446124/002/e25412026/09/13 15:16:19 INFO Uploading batch count=125422026/09/13 15:16:19 ERROR Upload failed error="upload failed" count=125432026/09/13 15:16:19 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown624446124/002/f25442026/09/13 15:16:19 ERROR Drain finished with paths left in queue remaining=125452026/09/13 15:16:19 ERROR Drain finished with paths left in queue remaining=102546--- PASS: TestDrainIsolatesPoisonPath (0.02s)2547--- PASS: TestDrainGivesUpWhenServerDown (0.02s)2548--- PASS: TestWorkerUploadsAndRemoves (0.03s)2549--- PASS: TestWorkerSkipsGCdPaths (0.04s)2550--- PASS: TestWorkerPrunesClosureDeps (0.04s)2551--- PASS: TestQueueConcurrentWriters (0.16s)25522026/09/13 15:16:19 ERROR Upload failed error="context deadline exceeded" count=225532026/09/13 15:16:19 ERROR Drain finished with paths left in queue remaining=42554--- PASS: TestDrainTimeout (0.21s)2555--- PASS: TestQueueRemoveLargeClosure (0.25s)25562026/09/13 15:16:20 INFO Uploading batch count=125572026/09/13 15:16:20 INFO Uploading batch count=125582026/09/13 15:16:20 INFO Uploading batch count=125592026/09/13 15:16:20 ERROR Upload failed error="upload failed" count=125602026/09/13 15:16:20 INFO Uploading batch count=125612026/09/13 15:16:20 ERROR Upload failed error="upload failed" count=125622026/09/13 15:16:20 INFO Uploading batch count=125632026/09/13 15:16:20 ERROR Upload failed error="upload failed" count=125642026/09/13 15:16:20 INFO Uploading batch count=125652026/09/13 15:16:20 ERROR Upload failed error="upload failed" count=125662026/09/13 15:16:20 ERROR Drain finished with paths left in queue remaining=12567--- PASS: TestRunNotBlockedByPoisonHead (1.03s)2568PASS