niks3-go-unit-tests
checks.aarch64-darwin.go-unit-tests
· build #209
· raw
1Running client tests...2=== RUN TestDoServerRequestAttachesToken3=== PAUSE TestDoServerRequestAttachesToken4=== RUN TestCaseHackSuffix5=== PAUSE TestCaseHackSuffix6=== RUN TestFilterOversizedClosures7=== PAUSE TestFilterOversizedClosures8=== RUN TestPartSizeForNAR9=== PAUSE TestPartSizeForNAR10=== RUN TestUploadMultipart_SupersededByPeer11=== PAUSE TestUploadMultipart_SupersededByPeer12=== RUN TestDumpPathCaseHackMatchesNix13--- PASS: TestDumpPathCaseHackMatchesNix (0.19s)14=== RUN TestDumpPathCaseHackCollision15--- PASS: TestDumpPathCaseHackCollision (0.00s)16=== RUN TestDumpPathMatchesNix17=== PAUSE TestDumpPathMatchesNix18=== RUN TestDumpPathSingleFile19=== PAUSE TestDumpPathSingleFile20=== RUN TestDumpPathWriterError21=== PAUSE TestDumpPathWriterError22=== RUN TestEncodeNixBase3223=== PAUSE TestEncodeNixBase3224=== RUN TestEncodeNixBase32WithRealHash25=== PAUSE TestEncodeNixBase32WithRealHash26=== RUN TestConvertHashToNix3227=== PAUSE TestConvertHashToNix3228=== RUN TestGetStorePathHash29=== PAUSE TestGetStorePathHash30=== RUN TestPathInfoHashCompatibility31=== PAUSE TestPathInfoHashCompatibility32=== RUN TestParsePathInfoJSON33=== PAUSE TestParsePathInfoJSON34=== RUN TestParsePathInfoJSONMultiplePaths35=== PAUSE TestParsePathInfoJSONMultiplePaths36=== RUN TestPathInfoCACompatibility37=== PAUSE TestPathInfoCACompatibility38=== RUN TestRateLimiterFeedback39=== PAUSE TestRateLimiterFeedback40=== RUN TestRateLimiterFeedback_400DoesNotCountAsSuccess41=== PAUSE TestRateLimiterFeedback_400DoesNotCountAsSuccess42=== RUN TestResolveStorePath43=== PAUSE TestResolveStorePath44=== RUN TestDoWithRetry_BodyReplayedViaGetBody45=== PAUSE TestDoWithRetry_BodyReplayedViaGetBody46=== RUN TestShellSplit47=== PAUSE TestShellSplit48=== RUN TestShellSplitErrors49=== PAUSE TestShellSplitErrors50=== RUN TestStreamPushReportsEveryPath51=== PAUSE TestStreamPushReportsEveryPath52=== RUN TestStreamPushBatchesUnderLoad53=== PAUSE TestStreamPushBatchesUnderLoad54=== RUN TestStreamPushIsolatesFailures55=== PAUSE TestStreamPushIsolatesFailures56=== RUN TestStreamPushGivesUpOnDeadServer57=== PAUSE TestStreamPushGivesUpOnDeadServer58=== RUN TestStreamPushRequestLine59=== PAUSE TestStreamPushRequestLine60=== RUN TestSetClientTLS61=== PAUSE TestSetClientTLS62=== RUN TestSetClientTLSDoesNotMutateDefaultTransport63=== PAUSE TestSetClientTLSDoesNotMutateDefaultTransport64=== RUN TestSetClientTLSErrors65=== PAUSE TestSetClientTLSErrors66=== RUN TestStaticToken67=== PAUSE TestStaticToken68=== RUN TestFileTokenReadsAndCaches69=== PAUSE TestFileTokenReadsAndCaches70=== RUN TestFileTokenMissing71=== PAUSE TestFileTokenMissing72=== RUN TestFileTokenEmpty73=== PAUSE TestFileTokenEmpty74=== RUN TestScriptTokenNoExpiryRerunsEveryCall75=== PAUSE TestScriptTokenNoExpiryRerunsEveryCall76=== RUN TestScriptTokenCachesUntilRefresh77=== PAUSE TestScriptTokenCachesUntilRefresh78=== RUN TestScriptTokenEmptyToken79=== PAUSE TestScriptTokenEmptyToken80=== RUN TestScriptTokenBadJSON81=== PAUSE TestScriptTokenBadJSON82=== RUN TestScriptTokenScriptFails83=== PAUSE TestScriptTokenScriptFails84=== RUN TestScriptTokenEmptyCommand85=== PAUSE TestScriptTokenEmptyCommand86=== CONT TestDoServerRequestAttachesToken87=== CONT TestShellSplit88=== CONT TestConvertHashToNix3289=== CONT TestPathInfoCACompatibility90--- PASS: TestShellSplit (0.00s)91=== CONT TestSetClientTLSErrors92=== RUN TestPathInfoCACompatibility/null_ca_field93=== CONT TestDumpPathMatchesNix94=== CONT TestEncodeNixBase32WithRealHash95--- PASS: TestEncodeNixBase32WithRealHash (0.00s)96=== CONT TestSetClientTLSDoesNotMutateDefaultTransport97=== CONT TestEncodeNixBase3298=== RUN TestEncodeNixBase32/test_string_hash99=== PAUSE TestEncodeNixBase32/test_string_hash100=== RUN TestEncodeNixBase32/empty_input101=== PAUSE TestEncodeNixBase32/empty_input102=== CONT TestDumpPathWriterError103=== CONT TestDumpPathSingleFile104=== CONT TestSetClientTLS105=== CONT TestStreamPushGivesUpOnDeadServer106=== RUN TestConvertHashToNix32/SRI_format_to_Nix32107=== PAUSE TestPathInfoCACompatibility/null_ca_field108=== RUN TestPathInfoCACompatibility/old_string_format_-_text109=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text110=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32111=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive1122026/09/16 10:25:53 ERROR Upload failed error="connection refused" count=201132026/09/16 10:25:53 ERROR Server seems unavailable, giving up on batch untried=17114=== RUN TestConvertHashToNix32/already_Nix32_format115=== PAUSE TestConvertHashToNix32/already_Nix32_format116=== RUN TestConvertHashToNix32/invalid_format117=== PAUSE TestConvertHashToNix32/invalid_format118--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)119=== CONT TestStreamPushRequestLine120=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive121=== RUN TestPathInfoCACompatibility/new_structured_format_-_text122=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text123=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method124=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method125=== CONT TestScriptTokenCachesUntilRefresh1262026/09/16 10:25:53 ERROR Upload failed error="stale build claim" count=1127=== CONT TestScriptTokenEmptyCommand128--- PASS: TestScriptTokenEmptyCommand (0.00s)129=== CONT TestScriptTokenScriptFails130--- PASS: TestStreamPushRequestLine (0.00s)131=== CONT TestScriptTokenBadJSON132=== RUN TestSetClientTLSErrors/missing_cert_file133=== PAUSE TestSetClientTLSErrors/missing_cert_file134=== RUN TestSetClientTLSErrors/missing_key_file135=== PAUSE TestSetClientTLSErrors/missing_key_file136=== RUN TestSetClientTLSErrors/missing_ca_file137=== PAUSE TestSetClientTLSErrors/missing_ca_file138=== RUN TestSetClientTLSErrors/invalid_ca_file139--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.01s)140=== PAUSE TestSetClientTLSErrors/invalid_ca_file141=== CONT TestScriptTokenEmptyToken142=== CONT TestFileTokenEmpty143--- PASS: TestFileTokenEmpty (0.00s)144=== CONT TestScriptTokenNoExpiryRerunsEveryCall145--- PASS: TestScriptTokenScriptFails (0.01s)146=== CONT TestPathInfoHashCompatibility147--- PASS: TestDoServerRequestAttachesToken (0.01s)148=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)149=== CONT TestParsePathInfoJSONMultiplePaths150=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths151=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths152=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths153=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths154=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)155=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon156=== CONT TestParsePathInfoJSON157=== RUN TestParsePathInfoJSON/Nix_format158=== PAUSE TestParsePathInfoJSON/Nix_format159=== RUN TestParsePathInfoJSON/Lix_format160=== PAUSE TestParsePathInfoJSON/Lix_format161=== RUN TestParsePathInfoJSON/empty_input162=== PAUSE TestParsePathInfoJSON/empty_input163=== RUN TestParsePathInfoJSON/whitespace_only164=== PAUSE TestParsePathInfoJSON/whitespace_only165=== RUN TestParsePathInfoJSON/invalid_JSON166=== PAUSE TestParsePathInfoJSON/invalid_JSON167=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon168=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI169=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI170=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512171=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512172=== CONT TestGetStorePathHash173=== RUN TestGetStorePathHash/valid_store_path174=== PAUSE TestGetStorePathHash/valid_store_path175=== RUN TestGetStorePathHash/basename_without_hyphen_should_error176=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error177=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error178=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error179=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error180=== RUN TestSetClientTLS/rejects_connection_without_client_cert181=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert182=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA183=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA184=== RUN TestSetClientTLS/preserves_debug_logging_transport185=== PAUSE TestSetClientTLS/preserves_debug_logging_transport186=== CONT TestPartSizeForNAR187=== RUN TestPartSizeForNAR/zero_stays_at_minimum188=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum189=== RUN TestPartSizeForNAR/small_stays_at_minimum190=== PAUSE TestPartSizeForNAR/small_stays_at_minimum191=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum192=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum193=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts194=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts195=== RUN TestPartSizeForNAR/1_TiB196=== PAUSE TestPartSizeForNAR/1_TiB197=== RUN TestPartSizeForNAR/5_TiB_S3_max_object198=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object199=== RUN TestPartSizeForNAR/capped_at_5_GiB200=== PAUSE TestPartSizeForNAR/capped_at_5_GiB201=== CONT TestFileTokenMissing202=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error203=== CONT TestUploadMultipart_SupersededByPeer204=== RUN TestUploadMultipart_SupersededByPeer/exists205=== PAUSE TestUploadMultipart_SupersededByPeer/exists206=== RUN TestUploadMultipart_SupersededByPeer/missing207=== PAUSE TestUploadMultipart_SupersededByPeer/missing208=== CONT TestFileTokenReadsAndCaches209=== CONT TestFilterOversizedClosures210=== RUN TestFilterOversizedClosures/no_limit_keeps_everything211=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything212=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped213=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped214=== RUN TestFilterOversizedClosures/all_closures_skipped215=== PAUSE TestFilterOversizedClosures/all_closures_skipped216=== CONT TestStreamPushBatchesUnderLoad217--- PASS: TestFileTokenMissing (0.00s)218=== CONT TestCaseHackSuffix219--- PASS: TestFileTokenReadsAndCaches (0.00s)220=== CONT TestStreamPushIsolatesFailures2212026/09/16 10:25:54 ERROR Upload failed error="bad path" count=3222--- PASS: TestStreamPushIsolatesFailures (0.00s)223=== CONT TestResolveStorePath224--- PASS: TestResolveStorePath (0.00s)225=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess2262026/09/16 10:25:54 WARN Rate limiter enabled after throttle name=server-test rate=5227--- PASS: TestScriptTokenEmptyToken (0.01s)228=== CONT TestDoWithRetry_BodyReplayedViaGetBody229--- PASS: TestScriptTokenBadJSON (0.02s)230=== CONT TestRateLimiterFeedback231=== RUN TestRateLimiterFeedback/429_enables_limiter232=== PAUSE TestRateLimiterFeedback/429_enables_limiter233=== RUN TestRateLimiterFeedback/503_enables_limiter234=== PAUSE TestRateLimiterFeedback/503_enables_limiter235=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter236=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter237=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter238=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter239=== CONT TestShellSplitErrors240--- PASS: TestShellSplitErrors (0.00s)241=== CONT TestStreamPushReportsEveryPath242--- PASS: TestStreamPushReportsEveryPath (0.00s)243=== CONT TestStaticToken244--- PASS: TestStaticToken (0.00s)245=== CONT TestEncodeNixBase32/test_string_hash246=== CONT TestEncodeNixBase32/empty_input247--- PASS: TestEncodeNixBase32 (0.00s)248 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)249 --- PASS: TestEncodeNixBase32/empty_input (0.00s)250=== CONT TestConvertHashToNix32/SRI_format_to_Nix32251=== CONT TestPathInfoCACompatibility/null_ca_field252=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive253=== CONT TestPathInfoCACompatibility/new_structured_format_-_text254=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method255=== CONT TestConvertHashToNix32/invalid_format256=== CONT TestConvertHashToNix32/already_Nix32_format257--- PASS: TestConvertHashToNix32 (0.00s)258 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)259 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)260 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)261=== CONT TestPathInfoCACompatibility/old_string_format_-_text262--- PASS: TestPathInfoCACompatibility (0.00s)263 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)264 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)265 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)266 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)267 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)268=== CONT TestSetClientTLSErrors/missing_cert_file269=== CONT TestSetClientTLSErrors/invalid_ca_file270=== CONT TestSetClientTLSErrors/missing_ca_file2712026/09/16 10:25:54 WARN Rate limiter enabled after throttle name=server-test rate=52722026/09/16 10:25:54 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:553222732026/09/16 10:25:54 WARN Rate limiter backed off name=server-test rate=52742026/09/16 10:25:54 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:55322275=== CONT TestSetClientTLSErrors/missing_key_file276=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths277=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths278--- PASS: TestParsePathInfoJSONMultiplePaths (0.00s)279 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)280 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)281=== CONT TestParsePathInfoJSON/Nix_format282--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.00s)283=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)284=== CONT TestParsePathInfoJSON/whitespace_only285=== CONT TestParsePathInfoJSON/empty_input286=== CONT TestParsePathInfoJSON/Lix_format287=== CONT TestParsePathInfoJSON/invalid_JSON288=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI289=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512290=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon291--- PASS: TestParsePathInfoJSON (0.00s)292 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)293 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)294 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)295 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)296 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)297=== CONT TestPartSizeForNAR/zero_stays_at_minimum298--- PASS: TestPathInfoHashCompatibility (0.00s)299 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)300 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)301 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)302 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)303=== CONT TestPartSizeForNAR/capped_at_5_GiB304=== CONT TestSetClientTLS/preserves_debug_logging_transport305=== CONT TestSetClientTLS/rejects_connection_without_client_cert306--- PASS: TestSetClientTLSErrors (0.01s)307 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)308 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)309 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)310 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)311=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA312=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts313=== CONT TestPartSizeForNAR/5_TiB_S3_max_object314=== CONT TestPartSizeForNAR/1_TiB315=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum316=== CONT TestPartSizeForNAR/small_stays_at_minimum317--- PASS: TestPartSizeForNAR (0.00s)318 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)319 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)320 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)321 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)322 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)323 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)324 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)325=== CONT TestGetStorePathHash/valid_store_path326=== CONT TestUploadMultipart_SupersededByPeer/exists327=== CONT TestGetStorePathHash/basename_without_hyphen_should_error328=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error329=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error330--- PASS: TestGetStorePathHash (0.00s)331 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)332 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)333 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)334 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)335=== CONT TestFilterOversizedClosures/no_limit_keeps_everything336=== CONT TestFilterOversizedClosures/all_closures_skipped3372026/09/16 10:25:54 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=50338=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped3392026/09/16 10:25:54 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=2000340--- PASS: TestFilterOversizedClosures (0.00s)341 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)342 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)343 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)344=== CONT TestUploadMultipart_SupersededByPeer/missing345--- PASS: TestUploadMultipart_SupersededByPeer (0.00s)346 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)347 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)348=== CONT TestRateLimiterFeedback/429_enables_limiter3492026/09/16 10:25:54 WARN Rate limiter enabled after throttle name=server-test rate=53502026/09/16 10:25:54 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:553313512026/09/16 10:25:54 WARN Rate limiter backed off name=server-test rate=5352=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter353=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter354=== CONT TestRateLimiterFeedback/503_enables_limiter3552026/09/16 10:25:54 WARN Rate limiter enabled after throttle name=server-test rate=53562026/09/16 10:25:54 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:553373572026/09/16 10:25:54 http: TLS handshake error from 127.0.0.1:55324: remote error: tls: bad certificate3582026/09/16 10:25:54 WARN Rate limiter backed off name=server-test rate=5359--- PASS: TestRateLimiterFeedback (0.00s)360 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)361 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)362 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)363 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)364--- PASS: TestSetClientTLS (0.01s)365 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.00s)366 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.00s)367 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.02s)368--- PASS: TestScriptTokenCachesUntilRefresh (0.04s)369--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.03s)370--- PASS: TestDumpPathWriterError (0.05s)371--- PASS: TestDumpPathSingleFile (0.05s)372--- PASS: TestCaseHackSuffix (0.04s)373--- PASS: TestDumpPathMatchesNix (0.07s)374--- PASS: TestStreamPushBatchesUnderLoad (0.10s)375--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)376PASS377Running server tests...378The files belonging to this database system will be owned by user "_nixbld1".379This user must also own the server process.380381The database cluster will be initialized with locale "C".382The default database encoding has accordingly been set to "SQL_ASCII".383The default text search configuration will be set to "english".384385Data page checksums are enabled.386387creating directory /nix/var/nix/builds/nix-36727-1823504073/postgres1438168957/data ... ok388creating subdirectories ... ok389selecting dynamic shared memory implementation ... posix390selecting default "max_connections" ... 100391selecting default "shared_buffers" ... 128MB392selecting default time zone ... UTC393creating configuration files ... ok394running bootstrap script ... ok395performing post-bootstrap initialization ... ok396syncing data to disk ... ok397398initdb: warning: enabling "trust" authentication for local connections399initdb: 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.400401Success. You can now start the database server using:402403 pg_ctl -D /nix/var/nix/builds/nix-36727-1823504073/postgres1438168957/data -l logfile start4044052026-09-16 10:25:57.142 UTC [36826] LOG: starting PostgreSQL 18.6 on aarch64-apple-darwin25.6.0, compiled by clang version 21.1.8, 64-bit4062026-09-16 10:25:57.142 UTC [36826] LOG: listening on Unix socket "/nix/var/nix/builds/nix-36727-1823504073/postgres1438168957/.s.PGSQL.5432"4072026-09-16 10:25:57.144 UTC [36833] LOG: database system was shut down at 2026-09-16 10:25:57 UTC4082026-09-16 10:25:57.145 UTC [36826] LOG: database system is ready to accept connections409/nix/var/nix/builds/nix-36727-1823504073/postgres1438168957:5432 - accepting connections410=== RUN TestService_AuthMiddleware411=== PAUSE TestService_AuthMiddleware412=== RUN TestService_AuthMiddleware_MTLSProxyHeader413=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader414=== RUN TestService_AuthMiddleware_MTLSBoundSubjects415=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects416=== RUN TestService_ReadAuthMiddleware417=== PAUSE TestService_ReadAuthMiddleware418=== RUN TestService_AuthMiddleware_OIDC419=== PAUSE TestService_AuthMiddleware_OIDC420=== RUN TestService_RequireScope_OIDC421=== PAUSE TestService_RequireScope_OIDC422=== RUN TestService_ReadScope_PublicByDefault423=== PAUSE TestService_ReadScope_PublicByDefault424=== RUN TestCacheConfigHandler425=== PAUSE TestCacheConfigHandler426=== RUN TestCacheStatsHandler427=== PAUSE TestCacheStatsHandler428=== RUN TestClaim_BuildWaitComplete429=== PAUSE TestClaim_BuildWaitComplete430=== RUN TestClaim_GCMarkedOutputCountsAsAbsent431=== PAUSE TestClaim_GCMarkedOutputCountsAsAbsent432=== RUN TestClaim_TooManyStreams433=== PAUSE TestClaim_TooManyStreams434=== RUN TestClaim_HolderDisconnectKeepsClaim435=== PAUSE TestClaim_HolderDisconnectKeepsClaim436=== RUN TestClaim_FailWakesWaitersButIsNotRemembered437=== PAUSE TestClaim_FailWakesWaitersButIsNotRemembered438=== RUN TestClaim_FailWithoutKindReleases439=== PAUSE TestClaim_FailWithoutKindReleases440=== RUN TestClaim_StaleHeartbeatStolen441=== PAUSE TestClaim_StaleHeartbeatStolen442=== RUN TestClaim_TwoInstances443=== PAUSE TestClaim_TwoInstances444=== RUN TestClaim_InputsTouched445=== PAUSE TestClaim_InputsTouched446=== RUN TestClaim_StreamsThroughServer447=== PAUSE TestClaim_StreamsThroughServer448=== RUN TestClientCADerivations449=== PAUSE TestClientCADerivations450=== RUN TestClientErrorHandling451=== PAUSE TestClientErrorHandling452=== RUN TestClientIntegration453=== PAUSE TestClientIntegration454=== RUN TestClientMultipleUploads455=== PAUSE TestClientMultipleUploads456=== RUN TestClientWithDependencies457=== PAUSE TestClientWithDependencies458=== RUN TestPinProtectsFromGC459=== PAUSE TestPinProtectsFromGC460=== RUN TestResolveDBConnectionString461=== PAUSE TestResolveDBConnectionString462=== RUN TestGCAdvisoryLockBlocksConcurrentRun4632026-09-16 10:25:59.519 UTC [36904] ERROR: relation "goose_db_version" does not exist at character 364642026-09-16 10:25:59.519 UTC [36904] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC4652026/09/16 10:25:59 OK 20241026095416_initial_model.sql (3.41ms)4662026/09/16 10:25:59 OK 20251210153512_drop_unused_gin_index.sql (411.21µs)4672026/09/16 10:25:59 OK 20251218171726_add_pins.sql (735.17µs)4682026/09/16 10:25:59 OK 20260628120000_add_object_size_and_stats.sql (772.63µs)4692026/09/16 10:25:59 OK 20260905000000_add_claims.sql (866.63µs)4702026/09/16 10:25:59 goose: successfully migrated database to version: 202609050000004712026/09/16 10:25:59 OK 1_commit_pending_closure.sql (899.63µs)4722026/09/16 10:25:59 OK 2_object_stats_trigger.sql (190.67µs)4732026/09/16 10:25:59 goose: up to current file version: 2474--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.36s)475=== RUN TestGCBugBareHashReferences476=== PAUSE TestGCBugBareHashReferences477=== RUN TestGCMetrics478=== PAUSE TestGCMetrics479=== RUN TestGCTaskStore_StartNew480=== PAUSE TestGCTaskStore_StartNew481=== RUN TestGCTaskStore_DeduplicateSameParams482=== PAUSE TestGCTaskStore_DeduplicateSameParams483=== RUN TestGCTaskStore_ConflictDifferentParams484=== PAUSE TestGCTaskStore_ConflictDifferentParams485=== RUN TestGCTaskStore_GetEmpty486=== PAUSE TestGCTaskStore_GetEmpty487=== RUN TestGCTaskStore_GetReturnsLatest488=== PAUSE TestGCTaskStore_GetReturnsLatest489=== RUN TestGCTaskStore_CompletedAllowsNewTask490=== PAUSE TestGCTaskStore_CompletedAllowsNewTask491=== RUN TestGCTaskStore_PhaseUpdates492=== PAUSE TestGCTaskStore_PhaseUpdates493=== RUN TestGCTaskStore_Fail494=== PAUSE TestGCTaskStore_Fail495=== RUN TestGracefulShutdownDrainsInflight496=== PAUSE TestGracefulShutdownDrainsInflight497=== RUN TestService_healthCheckHandler498=== PAUSE TestService_healthCheckHandler499=== RUN TestService_readinessHandler500=== PAUSE TestService_readinessHandler501=== RUN TestGenerateLandingPage502=== PAUSE TestGenerateLandingPage503=== RUN TestCacheConfigHandlerMaxNarSize504=== PAUSE TestCacheConfigHandlerMaxNarSize505=== RUN TestCreatePendingClosureRejectsOversizedNAR506=== PAUSE TestCreatePendingClosureRejectsOversizedNAR507=== RUN TestNARDeduplicationMetadataUploadBug508=== PAUSE TestNARDeduplicationMetadataUploadBug509=== RUN TestMetricsInventory510=== PAUSE TestMetricsInventory511=== RUN TestService_NativeMTLS512=== PAUSE TestService_NativeMTLS513=== RUN TestServerTLSConfig514=== PAUSE TestServerTLSConfig515=== RUN TestMultipartCleanup516=== PAUSE TestMultipartCleanup517=== RUN TestObjectStatsTrigger518=== PAUSE TestObjectStatsTrigger519=== RUN TestOrphanedObjectsGC520=== PAUSE TestOrphanedObjectsGC521=== RUN TestOrphanedObjectsGCStressTest522=== PAUSE TestOrphanedObjectsGCStressTest523=== RUN TestResurrectedObjectNotDeleted524=== PAUSE TestResurrectedObjectNotDeleted525=== RUN TestParseSingleRange526=== PAUSE TestParseSingleRange527=== RUN TestIsValidCachePath528=== PAUSE TestIsValidCachePath529=== RUN TestReadProxyNarinfo530=== PAUSE TestReadProxyNarinfo531=== RUN TestReadProxyNarinfoAlreadyDecompressed532=== PAUSE TestReadProxyNarinfoAlreadyDecompressed533=== RUN TestReadProxyNarStreaming534=== PAUSE TestReadProxyNarStreaming535=== RUN TestReadProxy404536=== PAUSE TestReadProxy404537=== RUN TestReadProxyInvalidPath538=== PAUSE TestReadProxyInvalidPath539=== RUN TestReadProxyHead540=== PAUSE TestReadProxyHead541=== RUN TestReadProxyConditionalGet542=== PAUSE TestReadProxyConditionalGet543=== RUN TestReadProxyRootRedirectsToIndexHTML544=== PAUSE TestReadProxyRootRedirectsToIndexHTML545=== RUN TestReadProxyDisabled546=== PAUSE TestReadProxyDisabled547=== RUN TestReadRedirectNar548=== PAUSE TestReadRedirectNar549=== RUN TestReadRedirectKeepsNarinfoProxied550=== PAUSE TestReadRedirectKeepsNarinfoProxied551=== RUN TestReadProxyRangeRequest552=== PAUSE TestReadProxyRangeRequest553=== RUN TestReadRedirectUsesPublicS3URL554=== PAUSE TestReadRedirectUsesPublicS3URL555=== RUN TestRedundantMultipartUpload556=== PAUSE TestRedundantMultipartUpload557=== RUN TestCompleteMultipartUpload_ErrorButObjectExists558=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists559=== RUN TestCompletedNarNotReofferedAcrossClosures560=== PAUSE TestCompletedNarNotReofferedAcrossClosures561=== RUN TestPresignedUploadRegisteredBeforeCommit562=== PAUSE TestPresignedUploadRegisteredBeforeCommit563=== RUN TestService_Rustfstest564=== PAUSE TestService_Rustfstest565=== RUN TestParseSize566=== PAUSE TestParseSize567=== RUN TestSkippedUploadsHandler568=== PAUSE TestSkippedUploadsHandler569=== RUN TestSystemdListenerNotActivated570--- PASS: TestSystemdListenerNotActivated (0.00s)571=== RUN TestWatchdogBeatsWhenHealthy572--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)573=== RUN TestWatchdogSkipsWhenUnhealthy5742026/09/16 10:25:59 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5752026/09/16 10:25:59 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5762026/09/16 10:25:59 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5772026/09/16 10:25:59 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5782026/09/16 10:25:59 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5792026/09/16 10:25:59 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5802026/09/16 10:25:59 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5812026/09/16 10:25:59 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5822026/09/16 10:25:59 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5832026/09/16 10:25:59 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"584--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)585=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle586=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle587=== RUN TestProxyWriteTimeout588=== PAUSE TestProxyWriteTimeout589=== RUN TestIsValidUploadKey590=== PAUSE TestIsValidUploadKey591=== RUN TestUploadHandlersRejectInvalidKeys592=== PAUSE TestUploadHandlersRejectInvalidKeys593=== RUN TestUploadHandlersRejectOversizedBody594=== PAUSE TestUploadHandlersRejectOversizedBody595=== RUN TestService_cleanupPendingClosuresHandler596=== PAUSE TestService_cleanupPendingClosuresHandler597=== RUN TestService_createPendingClosureHandler598=== PAUSE TestService_createPendingClosureHandler599=== RUN TestService_verifyS3Integrity600=== PAUSE TestService_verifyS3Integrity601=== RUN TestCompleteMultipartUnregistered602=== PAUSE TestCompleteMultipartUnregistered603=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT604=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT605=== CONT TestReadRedirectNar606=== CONT TestService_AuthMiddleware607=== CONT TestReadProxyDisabled608=== CONT TestClaim_TwoInstances609=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle610=== CONT TestMultipartCleanup611=== CONT TestReadProxyNarinfoAlreadyDecompressed612=== CONT TestServerTLSConfig613=== RUN TestServerTLSConfig/no_client_CA614=== PAUSE TestServerTLSConfig/no_client_CA615=== CONT TestClaim_StaleHeartbeatStolen616=== RUN TestServerTLSConfig/missing_CA_file617=== PAUSE TestServerTLSConfig/missing_CA_file618=== RUN TestServerTLSConfig/not_a_PEM_file619=== PAUSE TestServerTLSConfig/not_a_PEM_file620=== CONT TestServerTLSConfig/no_client_CA621=== CONT TestService_NativeMTLS622=== CONT TestGCTaskStore_GetEmpty623--- PASS: TestGCTaskStore_GetEmpty (0.00s)624=== CONT TestClaim_FailWithoutKindReleases6252026-09-16 10:26:00.199 UTC [36929] ERROR: relation "goose_db_version" does not exist at character 366262026-09-16 10:26:00.199 UTC [36929] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6272026-09-16 10:26:00.200 UTC [36930] ERROR: relation "goose_db_version" does not exist at character 366282026-09-16 10:26:00.200 UTC [36930] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6292026-09-16 10:26:00.202 UTC [36933] ERROR: relation "goose_db_version" does not exist at character 366302026-09-16 10:26:00.202 UTC [36933] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6312026-09-16 10:26:00.202 UTC [36936] ERROR: relation "goose_db_version" does not exist at character 366322026-09-16 10:26:00.202 UTC [36936] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6332026-09-16 10:26:00.204 UTC [36931] ERROR: relation "goose_db_version" does not exist at character 366342026-09-16 10:26:00.204 UTC [36931] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6352026-09-16 10:26:00.204 UTC [36932] ERROR: relation "goose_db_version" does not exist at character 366362026-09-16 10:26:00.204 UTC [36932] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6372026-09-16 10:26:00.204 UTC [36937] ERROR: relation "goose_db_version" does not exist at character 366382026-09-16 10:26:00.204 UTC [36937] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6392026-09-16 10:26:00.204 UTC [36935] ERROR: relation "goose_db_version" does not exist at character 366402026-09-16 10:26:00.204 UTC [36935] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6412026-09-16 10:26:00.204 UTC [36934] ERROR: relation "goose_db_version" does not exist at character 366422026-09-16 10:26:00.204 UTC [36934] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6432026-09-16 10:26:00.205 UTC [36938] ERROR: relation "goose_db_version" does not exist at character 366442026-09-16 10:26:00.205 UTC [36938] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6452026/09/16 10:26:00 OK 20241026095416_initial_model.sql (7.36ms)6462026/09/16 10:26:00 OK 20251210153512_drop_unused_gin_index.sql (9.64ms)6472026/09/16 10:26:00 OK 20251218171726_add_pins.sql (2.67ms)6482026/09/16 10:26:00 OK 20241026095416_initial_model.sql (17.08ms)6492026/09/16 10:26:00 OK 20241026095416_initial_model.sql (17.45ms)6502026/09/16 10:26:00 OK 20241026095416_initial_model.sql (16.66ms)6512026/09/16 10:26:00 OK 20241026095416_initial_model.sql (16.89ms)6522026/09/16 10:26:00 OK 20251210153512_drop_unused_gin_index.sql (1.06ms)6532026/09/16 10:26:00 OK 20251210153512_drop_unused_gin_index.sql (800.04µs)6542026/09/16 10:26:00 OK 20241026095416_initial_model.sql (17.15ms)6552026/09/16 10:26:00 OK 20241026095416_initial_model.sql (17.78ms)6562026/09/16 10:26:00 OK 20251210153512_drop_unused_gin_index.sql (1.04ms)6572026/09/16 10:26:00 OK 20241026095416_initial_model.sql (17.52ms)6582026/09/16 10:26:00 OK 20260628120000_add_object_size_and_stats.sql (2.21ms)6592026/09/16 10:26:00 OK 20251210153512_drop_unused_gin_index.sql (1.06ms)6602026/09/16 10:26:00 OK 20251210153512_drop_unused_gin_index.sql (723.08µs)6612026/09/16 10:26:00 OK 20241026095416_initial_model.sql (18.08ms)6622026/09/16 10:26:00 OK 20251218171726_add_pins.sql (1.36ms)6632026/09/16 10:26:00 OK 20251218171726_add_pins.sql (1.54ms)6642026/09/16 10:26:00 OK 20251210153512_drop_unused_gin_index.sql (1.12ms)6652026/09/16 10:26:00 OK 20251210153512_drop_unused_gin_index.sql (1.15ms)6662026/09/16 10:26:00 OK 20251210153512_drop_unused_gin_index.sql (772.21µs)6672026/09/16 10:26:00 OK 20251218171726_add_pins.sql (1.56ms)6682026/09/16 10:26:00 OK 20241026095416_initial_model.sql (17.07ms)6692026/09/16 10:26:00 OK 20260905000000_add_claims.sql (2.16ms)6702026/09/16 10:26:00 goose: successfully migrated database to version: 202609050000006712026/09/16 10:26:00 OK 20251218171726_add_pins.sql (1.65ms)6722026/09/16 10:26:00 OK 20260628120000_add_object_size_and_stats.sql (1.65ms)6732026/09/16 10:26:00 OK 20251218171726_add_pins.sql (1.58ms)6742026/09/16 10:26:00 OK 20251218171726_add_pins.sql (2.65ms)6752026/09/16 10:26:00 OK 20251210153512_drop_unused_gin_index.sql (864.33µs)6762026/09/16 10:26:00 OK 20260628120000_add_object_size_and_stats.sql (2.09ms)6772026/09/16 10:26:00 OK 20260628120000_add_object_size_and_stats.sql (1.54ms)6782026/09/16 10:26:00 OK 20251218171726_add_pins.sql (1.97ms)6792026/09/16 10:26:00 OK 1_commit_pending_closure.sql (1.08ms)6802026/09/16 10:26:00 OK 20251218171726_add_pins.sql (2.19ms)6812026/09/16 10:26:00 OK 2_object_stats_trigger.sql (401.17µs)6822026/09/16 10:26:00 goose: up to current file version: 26832026/09/16 10:26:00 OK 20260628120000_add_object_size_and_stats.sql (1.5ms)6842026/09/16 10:26:00 OK 20260905000000_add_claims.sql (2ms)6852026/09/16 10:26:00 goose: successfully migrated database to version: 202609050000006862026/09/16 10:26:00 OK 20260628120000_add_object_size_and_stats.sql (1.82ms)6872026/09/16 10:26:00 OK 20251218171726_add_pins.sql (1.73ms)6882026/09/16 10:26:00 OK 20260628120000_add_object_size_and_stats.sql (1.51ms)6892026/09/16 10:26:00 OK 20260905000000_add_claims.sql (2.35ms)6902026/09/16 10:26:00 goose: successfully migrated database to version: 202609050000006912026/09/16 10:26:00 OK 20260905000000_add_claims.sql (2.57ms)6922026/09/16 10:26:00 goose: successfully migrated database to version: 202609050000006932026/09/16 10:26:00 OK 20260628120000_add_object_size_and_stats.sql (1.86ms)6942026/09/16 10:26:00 OK 1_commit_pending_closure.sql (1ms)6952026/09/16 10:26:00 OK 20260628120000_add_object_size_and_stats.sql (3.07ms)6962026/09/16 10:26:00 OK 20260628120000_add_object_size_and_stats.sql (1.58ms)6972026/09/16 10:26:00 OK 2_object_stats_trigger.sql (797.42µs)6982026/09/16 10:26:00 goose: up to current file version: 26992026/09/16 10:26:00 OK 20260905000000_add_claims.sql (1.66ms)7002026/09/16 10:26:00 goose: successfully migrated database to version: 202609050000007012026/09/16 10:26:00 OK 20260905000000_add_claims.sql (2.71ms)7022026/09/16 10:26:00 goose: successfully migrated database to version: 202609050000007032026/09/16 10:26:00 OK 20260905000000_add_claims.sql (2.01ms)7042026/09/16 10:26:00 goose: successfully migrated database to version: 202609050000007052026/09/16 10:26:00 OK 1_commit_pending_closure.sql (1.15ms)7062026/09/16 10:26:00 OK 1_commit_pending_closure.sql (1.53ms)7072026/09/16 10:26:00 OK 2_object_stats_trigger.sql (501.79µs)7082026/09/16 10:26:00 goose: up to current file version: 27092026/09/16 10:26:00 OK 2_object_stats_trigger.sql (342.54µs)7102026/09/16 10:26:00 goose: up to current file version: 27112026/09/16 10:26:00 OK 1_commit_pending_closure.sql (885.63µs)7122026/09/16 10:26:00 OK 1_commit_pending_closure.sql (1.12ms)7132026/09/16 10:26:00 OK 20260905000000_add_claims.sql (2.02ms)7142026/09/16 10:26:00 goose: successfully migrated database to version: 202609050000007152026/09/16 10:26:00 OK 2_object_stats_trigger.sql (279.96µs)7162026/09/16 10:26:00 goose: up to current file version: 27172026/09/16 10:26:00 OK 1_commit_pending_closure.sql (1.18ms)7182026/09/16 10:26:00 OK 20260905000000_add_claims.sql (1.65ms)7192026/09/16 10:26:00 goose: successfully migrated database to version: 202609050000007202026/09/16 10:26:00 OK 2_object_stats_trigger.sql (296.17µs)7212026/09/16 10:26:00 goose: up to current file version: 27222026/09/16 10:26:00 OK 2_object_stats_trigger.sql (241.92µs)7232026/09/16 10:26:00 goose: up to current file version: 27242026/09/16 10:26:00 OK 20260905000000_add_claims.sql (2.5ms)7252026/09/16 10:26:00 goose: successfully migrated database to version: 202609050000007262026/09/16 10:26:00 OK 1_commit_pending_closure.sql (707.75µs)7272026/09/16 10:26:00 OK 1_commit_pending_closure.sql (694.63µs)7282026/09/16 10:26:00 OK 2_object_stats_trigger.sql (173.58µs)7292026/09/16 10:26:00 goose: up to current file version: 27302026/09/16 10:26:00 OK 2_object_stats_trigger.sql (186.46µs)7312026/09/16 10:26:00 goose: up to current file version: 27322026/09/16 10:26:00 OK 1_commit_pending_closure.sql (5.69ms)7332026/09/16 10:26:00 OK 2_object_stats_trigger.sql (184.5µs)7342026/09/16 10:26:00 goose: up to current file version: 27352026/09/16 10:26:00 INFO Received uploads request method=POST path=/api/pending_closures7362026/09/16 10:26:00 INFO Received cleanup request method=DELETE path=/api/pending_closures7372026/09/16 10:26:00 INFO Aborted multipart uploads count=1738--- PASS: TestReadRedirectNar (0.65s)739=== CONT TestClaim_FailWakesWaitersButIsNotRemembered740--- PASS: TestMultipartCleanup (0.65s)741=== CONT TestClaim_HolderDisconnectKeepsClaim742--- PASS: TestReadProxyDisabled (0.80s)743=== CONT TestReadProxyRootRedirectsToIndexHTML7442026/09/16 10:26:00 WARN claim: cannot clear write deadline error="feature not supported"7452026/09/16 10:26:00 WARN claim: cannot clear write deadline error="feature not supported"7462026/09/16 10:26:00 WARN claim: cannot clear write deadline error="feature not supported"7472026/09/16 10:26:00 INFO Received uploads request method=POST path=/api/pending_closures7482026/09/16 10:26:00 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"749--- PASS: TestService_AuthMiddleware (1.10s)750=== CONT TestReadProxyConditionalGet7512026-09-16 10:26:01.027 UTC [36950] ERROR: relation "goose_db_version" does not exist at character 367522026-09-16 10:26:01.027 UTC [36950] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7532026-09-16 10:26:01.027 UTC [36951] ERROR: relation "goose_db_version" does not exist at character 367542026-09-16 10:26:01.027 UTC [36951] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7552026/09/16 10:26:01 INFO Received uploads request method=POST path=/api/pending_closures7562026/09/16 10:26:01 OK 20241026095416_initial_model.sql (84.83ms)7572026/09/16 10:26:01 OK 20241026095416_initial_model.sql (90.98ms)7582026/09/16 10:26:01 OK 20251210153512_drop_unused_gin_index.sql (16.49ms)7592026/09/16 10:26:01 OK 20251210153512_drop_unused_gin_index.sql (17.58ms)7602026/09/16 10:26:01 OK 20251218171726_add_pins.sql (32.73ms)7612026/09/16 10:26:01 OK 20251218171726_add_pins.sql (26.78ms)7622026/09/16 10:26:01 OK 20260628120000_add_object_size_and_stats.sql (23.82ms)7632026/09/16 10:26:01 OK 20260628120000_add_object_size_and_stats.sql (37.39ms)7642026/09/16 10:26:01 OK 20260905000000_add_claims.sql (44.25ms)7652026/09/16 10:26:01 goose: successfully migrated database to version: 202609050000007662026/09/16 10:26:01 OK 20260905000000_add_claims.sql (57.1ms)7672026/09/16 10:26:01 goose: successfully migrated database to version: 202609050000007682026/09/16 10:26:01 OK 1_commit_pending_closure.sql (7.99ms)7692026/09/16 10:26:01 OK 1_commit_pending_closure.sql (8.13ms)7702026/09/16 10:26:01 OK 2_object_stats_trigger.sql (1.21ms)7712026/09/16 10:26:01 goose: up to current file version: 27722026/09/16 10:26:01 OK 2_object_stats_trigger.sql (1.2ms)7732026/09/16 10:26:01 goose: up to current file version: 27742026-09-16 10:26:01.324 UTC [36952] ERROR: relation "goose_db_version" does not exist at character 367752026-09-16 10:26:01.324 UTC [36952] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC776--- PASS: TestReadProxyNarinfoAlreadyDecompressed (1.54s)777=== CONT TestClaim_TooManyStreams7782026/09/16 10:26:01 INFO Received complete multipart upload request method=POST path=/api/multipart/complete7792026/09/16 10:26:01 OK 20241026095416_initial_model.sql (85.55ms)7802026/09/16 10:26:01 OK 20251210153512_drop_unused_gin_index.sql (9.11ms)7812026/09/16 10:26:01 OK 20251218171726_add_pins.sql (26.21ms)7822026/09/16 10:26:01 OK 20260628120000_add_object_size_and_stats.sql (24.85ms)7832026/09/16 10:26:01 WARN claim: cannot clear write deadline error="feature not supported"7842026/09/16 10:26:01 WARN claim: cannot clear write deadline error="feature not supported"785--- PASS: TestClaim_FailWithoutKindReleases (1.73s)786=== CONT TestReadProxyHead7872026/09/16 10:26:01 OK 20260905000000_add_claims.sql (29.58ms)7882026/09/16 10:26:01 goose: successfully migrated database to version: 202609050000007892026/09/16 10:26:01 OK 1_commit_pending_closure.sql (3.38ms)7902026/09/16 10:26:01 OK 2_object_stats_trigger.sql (671.96µs)7912026/09/16 10:26:01 goose: up to current file version: 27922026/09/16 10:26:01 WARN mTLS auth: subject not in bound subjects subject="CN=reader"7932026/09/16 10:26:01 WARN mTLS auth: subject not in bound subjects subject="CN=reader"794--- PASS: TestService_NativeMTLS (1.90s)795=== CONT TestReadProxyInvalidPath7962026-09-16 10:26:01.717 UTC [36958] ERROR: relation "goose_db_version" does not exist at character 367972026-09-16 10:26:01.717 UTC [36958] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7982026/09/16 10:26:01 INFO Received complete multipart upload request method=POST path=/api/multipart/complete7992026/09/16 10:26:01 OK 20241026095416_initial_model.sql (127.77ms)8002026/09/16 10:26:01 INFO Completed multipart upload object_key=nar/0000000000000000000000000000001600000000000000000000.nar.zst upload_id=MGI0NDE3ZTYtYjdlMy00NTZmLTkxYTctYjE3NGY3YzNjMzEzLjVmNGMzYTRlLTQxMDAtNGRhZS1iZjdmLWJlZWYxZTY5ODEyOHgxNzg5NTU0MzYwODA3NTQyMDAw parts=108012026/09/16 10:26:01 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign8022026/09/16 10:26:01 INFO Signed narinfos id=1 count=18032026/09/16 10:26:01 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete8042026/09/16 10:26:01 OK 20251210153512_drop_unused_gin_index.sql (13.35ms)8052026/09/16 10:26:01 INFO Completed upload id=1806--- PASS: TestClaim_TwoInstances (2.09s)807=== CONT TestReadProxy4048082026/09/16 10:26:01 OK 20251218171726_add_pins.sql (14.68ms)8092026/09/16 10:26:01 OK 20260628120000_add_object_size_and_stats.sql (16.82ms)8102026/09/16 10:26:01 WARN claim: cannot clear write deadline error="feature not supported"8112026/09/16 10:26:01 OK 20260905000000_add_claims.sql (3.64ms)8122026/09/16 10:26:01 goose: successfully migrated database to version: 202609050000008132026/09/16 10:26:01 OK 1_commit_pending_closure.sql (1.57ms)8142026/09/16 10:26:01 OK 2_object_stats_trigger.sql (373.63µs)8152026/09/16 10:26:01 goose: up to current file version: 28162026/09/16 10:26:01 WARN claim: cannot clear write deadline error="feature not supported"817--- PASS: TestClaim_StaleHeartbeatStolen (2.12s)818=== CONT TestReadProxyNarStreaming8192026/09/16 10:26:02 WARN claim: cannot clear write deadline error="feature not supported"8202026/09/16 10:26:02 WARN claim: cannot clear write deadline error="feature not supported"8212026-09-16 10:26:02.098 UTC [36968] ERROR: relation "goose_db_version" does not exist at character 368222026-09-16 10:26:02.098 UTC [36968] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8232026/09/16 10:26:02 OK 20241026095416_initial_model.sql (72.3ms)8242026/09/16 10:26:02 OK 20251210153512_drop_unused_gin_index.sql (2.57ms)8252026/09/16 10:26:02 WARN claim: cannot clear write deadline error="feature not supported"8262026/09/16 10:26:02 OK 20251218171726_add_pins.sql (25.86ms)8272026/09/16 10:26:02 OK 20260628120000_add_object_size_and_stats.sql (6.29ms)8282026/09/16 10:26:02 WARN claim: cannot clear write deadline error="feature not supported"8292026/09/16 10:26:02 WARN claim: cannot clear write deadline error="feature not supported"830--- PASS: TestClaim_FailWakesWaitersButIsNotRemembered (1.77s)831=== CONT TestPinProtectsFromGC8322026/09/16 10:26:02 OK 20260905000000_add_claims.sql (26.13ms)8332026/09/16 10:26:02 goose: successfully migrated database to version: 202609050000008342026/09/16 10:26:02 OK 1_commit_pending_closure.sql (7.96ms)8352026/09/16 10:26:02 OK 2_object_stats_trigger.sql (740.96µs)8362026/09/16 10:26:02 goose: up to current file version: 28372026-09-16 10:26:02.384 UTC [36972] ERROR: relation "goose_db_version" does not exist at character 368382026-09-16 10:26:02.384 UTC [36972] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC839--- PASS: TestReadProxyRootRedirectsToIndexHTML (1.78s)840=== CONT TestGCTaskStore_ConflictDifferentParams841--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)842=== CONT TestGCTaskStore_DeduplicateSameParams843--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)844=== CONT TestGCTaskStore_StartNew845--- PASS: TestGCTaskStore_StartNew (0.00s)846=== CONT TestClaim_GCMarkedOutputCountsAsAbsent8472026/09/16 10:26:02 OK 20241026095416_initial_model.sql (77.44ms)8482026/09/16 10:26:02 OK 20251210153512_drop_unused_gin_index.sql (7.7ms)8492026/09/16 10:26:02 OK 20251218171726_add_pins.sql (23.74ms)8502026/09/16 10:26:02 OK 20260628120000_add_object_size_and_stats.sql (13.71ms)8512026/09/16 10:26:02 OK 20260905000000_add_claims.sql (36.14ms)8522026-09-16 10:26:02.573 UTC [36975] ERROR: relation "goose_db_version" does not exist at character 368532026-09-16 10:26:02.573 UTC [36975] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8542026/09/16 10:26:02 goose: successfully migrated database to version: 202609050000008552026/09/16 10:26:02 OK 1_commit_pending_closure.sql (4.68ms)8562026/09/16 10:26:02 OK 2_object_stats_trigger.sql (1.2ms)8572026/09/16 10:26:02 goose: up to current file version: 2858--- PASS: TestReadProxyConditionalGet (1.67s)859=== CONT TestGCMetrics8602026/09/16 10:26:02 WARN claim: cannot clear write deadline error="feature not supported"8612026-09-16 10:26:02.648 UTC [36979] ERROR: relation "goose_db_version" does not exist at character 368622026-09-16 10:26:02.648 UTC [36979] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8632026-09-16 10:26:02.664 UTC [36980] ERROR: relation "goose_db_version" does not exist at character 368642026-09-16 10:26:02.664 UTC [36980] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8652026/09/16 10:26:02 OK 20241026095416_initial_model.sql (64.78ms)8662026/09/16 10:26:02 OK 20251210153512_drop_unused_gin_index.sql (9.93ms)8672026/09/16 10:26:02 OK 20251218171726_add_pins.sql (16.24ms)8682026/09/16 10:26:02 OK 20260628120000_add_object_size_and_stats.sql (21.84ms)8692026/09/16 10:26:02 WARN claim: cannot clear write deadline error="feature not supported"8702026/09/16 10:26:02 OK 20260905000000_add_claims.sql (9.98ms)8712026/09/16 10:26:02 goose: successfully migrated database to version: 202609050000008722026/09/16 10:26:02 OK 20241026095416_initial_model.sql (65.02ms)8732026/09/16 10:26:02 OK 1_commit_pending_closure.sql (5.21ms)8742026/09/16 10:26:02 OK 2_object_stats_trigger.sql (1.29ms)8752026/09/16 10:26:02 goose: up to current file version: 28762026/09/16 10:26:02 OK 20241026095416_initial_model.sql (49.39ms)8772026/09/16 10:26:02 OK 20251210153512_drop_unused_gin_index.sql (2.26ms)878--- PASS: TestClaim_TooManyStreams (1.40s)879=== CONT TestClaim_BuildWaitComplete8802026/09/16 10:26:02 OK 20251210153512_drop_unused_gin_index.sql (10.08ms)8812026/09/16 10:26:02 OK 20251218171726_add_pins.sql (17.6ms)8822026/09/16 10:26:02 OK 20251218171726_add_pins.sql (14.83ms)8832026/09/16 10:26:02 OK 20260628120000_add_object_size_and_stats.sql (14.73ms)8842026/09/16 10:26:02 OK 20260628120000_add_object_size_and_stats.sql (9.7ms)8852026/09/16 10:26:02 OK 20260905000000_add_claims.sql (12.9ms)8862026/09/16 10:26:02 goose: successfully migrated database to version: 202609050000008872026/09/16 10:26:02 OK 1_commit_pending_closure.sql (2.55ms)8882026/09/16 10:26:02 OK 2_object_stats_trigger.sql (359µs)8892026/09/16 10:26:02 goose: up to current file version: 28902026/09/16 10:26:02 OK 20260905000000_add_claims.sql (19.09ms)8912026/09/16 10:26:02 goose: successfully migrated database to version: 202609050000008922026/09/16 10:26:02 OK 1_commit_pending_closure.sql (1.78ms)8932026/09/16 10:26:02 OK 2_object_stats_trigger.sql (334.25µs)8942026/09/16 10:26:02 goose: up to current file version: 2895--- PASS: TestReadProxyHead (1.34s)896=== CONT TestGCBugBareHashReferences8972026-09-16 10:26:03.025 UTC [36986] ERROR: relation "goose_db_version" does not exist at character 368982026-09-16 10:26:03.025 UTC [36986] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC899--- PASS: TestReadProxyInvalidPath (1.33s)900=== CONT TestCacheStatsHandler9012026/09/16 10:26:03 OK 20241026095416_initial_model.sql (66.16ms)9022026/09/16 10:26:03 OK 20251210153512_drop_unused_gin_index.sql (2.22ms)9032026-09-16 10:26:03.122 UTC [36989] ERROR: relation "goose_db_version" does not exist at character 369042026-09-16 10:26:03.122 UTC [36989] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9052026/09/16 10:26:03 OK 20251218171726_add_pins.sql (11.63ms)9062026/09/16 10:26:03 OK 20260628120000_add_object_size_and_stats.sql (12.91ms)9072026/09/16 10:26:03 OK 20260905000000_add_claims.sql (33.92ms)9082026/09/16 10:26:03 goose: successfully migrated database to version: 202609050000009092026/09/16 10:26:03 OK 1_commit_pending_closure.sql (3.15ms)9102026/09/16 10:26:03 OK 2_object_stats_trigger.sql (508.33µs)9112026/09/16 10:26:03 goose: up to current file version: 2912--- PASS: TestReadProxy404 (1.31s)913=== CONT TestSkippedUploadsHandler9142026/09/16 10:26:03 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000915--- PASS: TestSkippedUploadsHandler (0.00s)916=== CONT TestResolveDBConnectionString917=== RUN TestResolveDBConnectionString/flag_wins918=== PAUSE TestResolveDBConnectionString/flag_wins919=== RUN TestResolveDBConnectionString/file_when_flag_empty920=== PAUSE TestResolveDBConnectionString/file_when_flag_empty921=== RUN TestResolveDBConnectionString/missing_file_is_an_error922=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error923=== RUN TestResolveDBConnectionString/PGHOST_allows_empty924=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty925=== RUN TestResolveDBConnectionString/nothing_configured926=== PAUSE TestResolveDBConnectionString/nothing_configured927=== CONT TestCacheConfigHandler928=== RUN TestCacheConfigHandler/full_config,_no_issuer929=== PAUSE TestCacheConfigHandler/full_config,_no_issuer930=== RUN TestCacheConfigHandler/no_cache_url_configured931=== PAUSE TestCacheConfigHandler/no_cache_url_configured932=== RUN TestCacheConfigHandler/no_signing_keys933=== PAUSE TestCacheConfigHandler/no_signing_keys934=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator935=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator936=== CONT TestService_cleanupPendingClosuresHandler9372026/09/16 10:26:03 OK 20241026095416_initial_model.sql (73.16ms)9382026/09/16 10:26:03 OK 20251210153512_drop_unused_gin_index.sql (10.21ms)9392026/09/16 10:26:03 OK 20251218171726_add_pins.sql (16.39ms)9402026/09/16 10:26:03 OK 20260628120000_add_object_size_and_stats.sql (10.3ms)9412026/09/16 10:26:03 OK 20260905000000_add_claims.sql (22.42ms)9422026/09/16 10:26:03 goose: successfully migrated database to version: 202609050000009432026/09/16 10:26:03 OK 1_commit_pending_closure.sql (5.83ms)9442026/09/16 10:26:03 OK 2_object_stats_trigger.sql (398.33µs)9452026/09/16 10:26:03 goose: up to current file version: 29462026-09-16 10:26:03.311 UTC [36993] ERROR: relation "goose_db_version" does not exist at character 369472026-09-16 10:26:03.311 UTC [36993] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC948--- PASS: TestReadProxyNarStreaming (1.44s)949=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT9502026/09/16 10:26:03 OK 20241026095416_initial_model.sql (43.15ms)9512026/09/16 10:26:03 OK 20251210153512_drop_unused_gin_index.sql (6.69ms)9522026/09/16 10:26:03 OK 20251218171726_add_pins.sql (11.65ms)9532026/09/16 10:26:03 OK 20260628120000_add_object_size_and_stats.sql (15.4ms)9542026/09/16 10:26:03 OK 20260905000000_add_claims.sql (17.52ms)9552026/09/16 10:26:03 goose: successfully migrated database to version: 202609050000009562026/09/16 10:26:03 OK 1_commit_pending_closure.sql (1.97ms)9572026/09/16 10:26:03 OK 2_object_stats_trigger.sql (404.04µs)9582026/09/16 10:26:03 goose: up to current file version: 29592026-09-16 10:26:03.494 UTC [36996] ERROR: relation "goose_db_version" does not exist at character 369602026-09-16 10:26:03.494 UTC [36996] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9612026/09/16 10:26:03 OK 20241026095416_initial_model.sql (51.66ms)9622026/09/16 10:26:03 OK 20251210153512_drop_unused_gin_index.sql (1.66ms)9632026/09/16 10:26:03 OK 20251218171726_add_pins.sql (7.8ms)9642026-09-16 10:26:03.626 UTC [36998] ERROR: relation "goose_db_version" does not exist at character 369652026-09-16 10:26:03.626 UTC [36998] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9662026/09/16 10:26:03 OK 20260628120000_add_object_size_and_stats.sql (48.47ms)9672026/09/16 10:26:03 OK 20260905000000_add_claims.sql (13.6ms)9682026/09/16 10:26:03 goose: successfully migrated database to version: 202609050000009692026/09/16 10:26:03 OK 1_commit_pending_closure.sql (1.27ms)9702026/09/16 10:26:03 OK 2_object_stats_trigger.sql (433.79µs)9712026/09/16 10:26:03 goose: up to current file version: 29722026/09/16 10:26:03 INFO Received uploads request method=POST path=/api/pending_closures9732026/09/16 10:26:03 OK 20241026095416_initial_model.sql (69.94ms)9742026/09/16 10:26:03 OK 20251210153512_drop_unused_gin_index.sql (7.49ms)9752026/09/16 10:26:03 OK 20251218171726_add_pins.sql (8.3ms)9762026/09/16 10:26:03 OK 20260628120000_add_object_size_and_stats.sql (26.11ms)9772026/09/16 10:26:03 OK 20260905000000_add_claims.sql (19.47ms)9782026/09/16 10:26:03 goose: successfully migrated database to version: 202609050000009792026/09/16 10:26:03 OK 1_commit_pending_closure.sql (2.84ms)9802026/09/16 10:26:03 OK 2_object_stats_trigger.sql (297.92µs)9812026/09/16 10:26:03 goose: up to current file version: 2982=== NAME TestPinProtectsFromGC983 client_integration_test.go:648: Pinned store path: /nix/var/nix/builds/nix-36727-1823504073/TestPinProtectsFromGC1021103562/001/store/l13s3pfs661w2fkga735vc51isdkhydr-pinned-file.txt984 client_integration_test.go:649: Unpinned store path: /nix/var/nix/builds/nix-36727-1823504073/TestPinProtectsFromGC1021103562/001/store/nww5zdyb32ahfvzxq49bj844ja10vqp1-unpinned-file.txt9852026-09-16 10:26:03.858 UTC [37011] ERROR: relation "goose_db_version" does not exist at character 369862026-09-16 10:26:03.858 UTC [37011] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9872026/09/16 10:26:03 INFO Aborted multipart uploads count=09882026/09/16 10:26:03 WARN Force mode enabled - objects will be deleted immediately without grace period9892026/09/16 10:26:03 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=09902026/09/16 10:26:03 INFO Vacuumed table table=pending_closures9912026/09/16 10:26:03 INFO Vacuumed table table=pending_objects9922026/09/16 10:26:03 INFO Vacuumed table table=multipart_uploads9932026/09/16 10:26:03 INFO Vacuumed table table=closures9942026/09/16 10:26:03 INFO Vacuumed table table=objects995--- PASS: TestGCMetrics (1.34s)996=== CONT TestParseSize997--- PASS: TestParseSize (0.00s)998=== CONT TestCompleteMultipartUnregistered9992026/09/16 10:26:03 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"10002026/09/16 10:26:03 OK 20241026095416_initial_model.sql (78.57ms)10012026/09/16 10:26:03 OK 20251210153512_drop_unused_gin_index.sql (815.92µs)10022026/09/16 10:26:03 INFO Received uploads request method=POST path=/api/pending_closures10032026/09/16 10:26:03 OK 20251218171726_add_pins.sql (10.54ms)10042026/09/16 10:26:03 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)10052026/09/16 10:26:03 INFO Uploading l13s3pfs661w2fkga735vc51isdkhydr-pinned-file.txt (128B)10062026/09/16 10:26:03 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"10072026/09/16 10:26:04 OK 20260628120000_add_object_size_and_stats.sql (27.91ms)10082026/09/16 10:26:04 WARN Failed to register uploaded object key=l13s3pfs661w2fkga735vc51isdkhydr.ls error="server returned 404: 404 page not found\n"10092026/09/16 10:26:04 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign10102026/09/16 10:26:04 INFO Signed narinfos id=1 count=110112026/09/16 10:26:04 INFO Uploading 1 narinfos10122026/09/16 10:26:04 WARN Failed to register uploaded object key=l13s3pfs661w2fkga735vc51isdkhydr.narinfo error="server returned 404: 404 page not found\n"10132026/09/16 10:26:04 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete10142026/09/16 10:26:04 OK 20260905000000_add_claims.sql (35.56ms)10152026/09/16 10:26:04 goose: successfully migrated database to version: 2026090500000010162026/09/16 10:26:04 INFO Completed upload id=110172026/09/16 10:26:04 INFO Upload complete. (159ms)10182026/09/16 10:26:04 OK 1_commit_pending_closure.sql (1.85ms)10192026/09/16 10:26:04 OK 2_object_stats_trigger.sql (311µs)10202026/09/16 10:26:04 goose: up to current file version: 210212026-09-16 10:26:04.055 UTC [37021] ERROR: relation "goose_db_version" does not exist at character 3610222026-09-16 10:26:04.055 UTC [37021] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10232026/09/16 10:26:04 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"10242026/09/16 10:26:04 WARN claim: cannot clear write deadline error="feature not supported"10252026/09/16 10:26:04 OK 20241026095416_initial_model.sql (50.17ms)10262026/09/16 10:26:04 OK 20251210153512_drop_unused_gin_index.sql (2.38ms)10272026/09/16 10:26:04 WARN claim: cannot clear write deadline error="feature not supported"10282026/09/16 10:26:04 WARN claim: cannot clear write deadline error="feature not supported"10292026/09/16 10:26:04 INFO Received uploads request method=POST path=/api/pending_closures10302026/09/16 10:26:04 OK 20251218171726_add_pins.sql (13.13ms)10312026/09/16 10:26:04 INFO Received uploads request method=POST path=/api/pending_closures10322026/09/16 10:26:04 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)10332026/09/16 10:26:04 INFO Uploading nww5zdyb32ahfvzxq49bj844ja10vqp1-unpinned-file.txt (128B)10342026/09/16 10:26:04 OK 20260628120000_add_object_size_and_stats.sql (26.04ms)10352026/09/16 10:26:04 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"10362026/09/16 10:26:04 WARN Failed to register uploaded object key=nww5zdyb32ahfvzxq49bj844ja10vqp1.ls error="server returned 404: 404 page not found\n"10372026/09/16 10:26:04 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign10382026/09/16 10:26:04 INFO Signed narinfos id=2 count=110392026/09/16 10:26:04 INFO Uploading 1 narinfos10402026/09/16 10:26:04 WARN Failed to register uploaded object key=nww5zdyb32ahfvzxq49bj844ja10vqp1.narinfo error="server returned 404: 404 page not found\n"10412026/09/16 10:26:04 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete10422026/09/16 10:26:04 INFO Completed upload id=210432026/09/16 10:26:04 INFO Upload complete. (134ms)10442026/09/16 10:26:04 OK 20260905000000_add_claims.sql (33.09ms)10452026/09/16 10:26:04 goose: successfully migrated database to version: 2026090500000010462026/09/16 10:26:04 OK 1_commit_pending_closure.sql (5.29ms)10472026/09/16 10:26:04 OK 2_object_stats_trigger.sql (619.5µs)10482026/09/16 10:26:04 goose: up to current file version: 210492026/09/16 10:26:04 INFO Received create pin request method=POST path=/api/pins/myapp10502026-09-16 10:26:04.256 UTC [37029] ERROR: relation "goose_db_version" does not exist at character 3610512026-09-16 10:26:04.256 UTC [37029] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10522026/09/16 10:26:04 INFO Created/updated pin name=myapp store_path=/nix/var/nix/builds/nix-36727-1823504073/TestPinProtectsFromGC1021103562/001/store/l13s3pfs661w2fkga735vc51isdkhydr-pinned-file.txt narinfo_key=l13s3pfs661w2fkga735vc51isdkhydr.narinfo10532026/09/16 10:26:04 INFO Starting cleanup of old closures method=DELETE path=/api/closures10542026/09/16 10:26:04 INFO Garbage collection started10552026/09/16 10:26:04 INFO Aborted multipart uploads count=010562026/09/16 10:26:04 WARN Force mode enabled - objects will be deleted immediately without grace period10572026/09/16 10:26:04 OK 20241026095416_initial_model.sql (113.52ms)10582026/09/16 10:26:04 OK 20251210153512_drop_unused_gin_index.sql (6.35ms)10592026/09/16 10:26:04 OK 20251218171726_add_pins.sql (17.19ms)10602026/09/16 10:26:04 OK 20260628120000_add_object_size_and_stats.sql (32.56ms)10612026/09/16 10:26:04 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=010622026/09/16 10:26:04 INFO Vacuumed table table=pending_closures10632026/09/16 10:26:04 OK 20260905000000_add_claims.sql (50.57ms)10642026/09/16 10:26:04 goose: successfully migrated database to version: 2026090500000010652026/09/16 10:26:04 INFO Vacuumed table table=pending_objects10662026/09/16 10:26:04 INFO Vacuumed table table=multipart_uploads10672026/09/16 10:26:04 INFO Vacuumed table table=closures10682026/09/16 10:26:04 OK 1_commit_pending_closure.sql (4.5ms)10692026/09/16 10:26:04 OK 2_object_stats_trigger.sql (234.58µs)10702026/09/16 10:26:04 goose: up to current file version: 210712026/09/16 10:26:04 INFO Vacuumed table table=objects1072--- PASS: TestClaim_HolderDisconnectKeepsClaim (4.13s)1073=== CONT TestService_verifyS3Integrity1074--- PASS: TestGCBugBareHashReferences (1.72s)1075=== CONT TestService_createPendingClosureHandler1076--- PASS: TestCacheStatsHandler (1.57s)1077=== CONT TestService_Rustfstest10782026/09/16 10:26:04 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10792026/09/16 10:26:04 INFO Completed multipart upload object_key=nar/0000000000000000000000000000001100000000000000000000.nar.zst upload_id=MGI0NDE3ZTYtYjdlMy00NTZmLTkxYTctYjE3NGY3YzNjMzEzLmNhOGZjZDI3LTJiYzQtNDU1YS1iMDYxLWNhMmQ1NTA2MDg1Y3gxNzg5NTU0MzYzNzQxNjQ1MDAw parts=1010802026/09/16 10:26:04 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete10812026/09/16 10:26:04 INFO Completed upload id=110822026/09/16 10:26:04 WARN claim: cannot clear write deadline error="feature not supported"10832026/09/16 10:26:04 WARN claim: cannot clear write deadline error="feature not supported"1084--- PASS: TestClaim_GCMarkedOutputCountsAsAbsent (2.41s)1085=== CONT TestRedundantMultipartUpload10862026/09/16 10:26:04 INFO Received cleanup request method=DELETE path=/api/pending_closures10872026/09/16 10:26:04 INFO Aborted multipart uploads count=010882026/09/16 10:26:04 INFO Received uploads request method=POST path=/api/pending_closures10892026/09/16 10:26:04 INFO Received cleanup request method=DELETE path=/api/pending_closures10902026/09/16 10:26:04 INFO Aborted multipart uploads count=110912026/09/16 10:26:04 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete10922026-09-16 10:26:04.885 UTC [37021] ERROR: Closure does not exist: id=110932026-09-16 10:26:04.885 UTC [37021] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 16 at RAISE10942026-09-16 10:26:04.885 UTC [37021] STATEMENT: -- name: CommitPendingClosure :exec1095 SELECT commit_pending_closure($1::bigint)1096 1097--- PASS: TestService_cleanupPendingClosuresHandler (1.67s)1098=== CONT TestReadRedirectUsesPublicS3URL10992026/09/16 10:26:05 INFO Received uploads request method=POST path=/api/pending_closures11002026-09-16 10:26:05.052 UTC [37045] ERROR: relation "goose_db_version" does not exist at character 3611012026-09-16 10:26:05.052 UTC [37045] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1102--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (1.71s)1103=== CONT TestPresignedUploadRegisteredBeforeCommit11042026/09/16 10:26:05 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11052026/09/16 10:26:05 OK 20241026095416_initial_model.sql (69.06ms)11062026/09/16 10:26:05 OK 20251210153512_drop_unused_gin_index.sql (1.04ms)11072026/09/16 10:26:05 OK 20251218171726_add_pins.sql (3.09ms)11082026/09/16 10:26:05 INFO Completed multipart upload object_key=nar/0000000000000000000000000000001000000000000000000000.nar.zst upload_id=MGI0NDE3ZTYtYjdlMy00NTZmLTkxYTctYjE3NGY3YzNjMzEzLmYxYWM2NDIxLTNkY2ItNGU2NC05OTExLTQwNGRhOThkMTBjOXgxNzg5NTU0MzY0MTYyMTA3MDAw parts=1011092026/09/16 10:26:05 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign11102026/09/16 10:26:05 INFO Signed narinfos id=1 count=111112026/09/16 10:26:05 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete11122026/09/16 10:26:05 INFO Received uploads request method=POST path=/api/pending_closures11132026/09/16 10:26:05 OK 20260628120000_add_object_size_and_stats.sql (3.79ms)11142026/09/16 10:26:05 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign11152026/09/16 10:26:05 INFO Signed narinfos id=2 count=111162026/09/16 10:26:05 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete11172026/09/16 10:26:05 OK 20260905000000_add_claims.sql (2.36ms)11182026/09/16 10:26:05 goose: successfully migrated database to version: 2026090500000011192026/09/16 10:26:05 INFO Completed upload id=211202026/09/16 10:26:05 OK 1_commit_pending_closure.sql (2ms)11212026/09/16 10:26:05 WARN claim: cannot clear write deadline error="feature not supported"1122--- PASS: TestClaim_BuildWaitComplete (2.43s)11232026/09/16 10:26:05 OK 2_object_stats_trigger.sql (846.17µs)11242026/09/16 10:26:05 goose: up to current file version: 21125=== CONT TestReadProxyRangeRequest11262026/09/16 10:26:05 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11272026/09/16 10:26:05 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst1128--- PASS: TestCompleteMultipartUnregistered (1.38s)1129=== CONT TestCompletedNarNotReofferedAcrossClosures11302026-09-16 10:26:05.382 UTC [37052] ERROR: relation "goose_db_version" does not exist at character 3611312026-09-16 10:26:05.382 UTC [37052] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11322026-09-16 10:26:05.382 UTC [37053] ERROR: relation "goose_db_version" does not exist at character 3611332026-09-16 10:26:05.382 UTC [37053] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11342026/09/16 10:26:05 OK 20241026095416_initial_model.sql (8.93ms)11352026/09/16 10:26:05 OK 20241026095416_initial_model.sql (10.51ms)11362026/09/16 10:26:05 OK 20251210153512_drop_unused_gin_index.sql (785.92µs)11372026/09/16 10:26:05 OK 20251210153512_drop_unused_gin_index.sql (433.04µs)11382026/09/16 10:26:05 OK 20251218171726_add_pins.sql (1.16ms)11392026/09/16 10:26:05 OK 20251218171726_add_pins.sql (1.65ms)11402026/09/16 10:26:05 OK 20260628120000_add_object_size_and_stats.sql (10.42ms)11412026/09/16 10:26:05 OK 20260628120000_add_object_size_and_stats.sql (9.62ms)11422026/09/16 10:26:05 OK 20260905000000_add_claims.sql (3.32ms)11432026/09/16 10:26:05 goose: successfully migrated database to version: 2026090500000011442026/09/16 10:26:05 OK 20260905000000_add_claims.sql (3.65ms)11452026/09/16 10:26:05 goose: successfully migrated database to version: 2026090500000011462026/09/16 10:26:05 OK 1_commit_pending_closure.sql (1.23ms)11472026/09/16 10:26:05 OK 1_commit_pending_closure.sql (931.83µs)11482026/09/16 10:26:05 OK 2_object_stats_trigger.sql (244.5µs)11492026/09/16 10:26:05 goose: up to current file version: 211502026/09/16 10:26:05 OK 2_object_stats_trigger.sql (281.33µs)11512026/09/16 10:26:05 goose: up to current file version: 211522026-09-16 10:26:05.425 UTC [37054] ERROR: relation "goose_db_version" does not exist at character 3611532026-09-16 10:26:05.425 UTC [37054] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11542026/09/16 10:26:05 OK 20241026095416_initial_model.sql (60.96ms)11552026/09/16 10:26:05 OK 20251210153512_drop_unused_gin_index.sql (7.18ms)11562026/09/16 10:26:05 OK 20251218171726_add_pins.sql (10.08ms)11572026/09/16 10:26:05 OK 20260628120000_add_object_size_and_stats.sql (28.88ms)1158--- PASS: TestService_Rustfstest (0.99s)1159=== CONT TestReadRedirectKeepsNarinfoProxied11602026/09/16 10:26:05 OK 20260905000000_add_claims.sql (46.54ms)11612026/09/16 10:26:05 goose: successfully migrated database to version: 2026090500000011622026/09/16 10:26:05 OK 1_commit_pending_closure.sql (8.3ms)11632026/09/16 10:26:05 OK 2_object_stats_trigger.sql (435.67µs)11642026/09/16 10:26:05 goose: up to current file version: 211652026/09/16 10:26:05 INFO Received uploads request method=POST path=/api/pending_closures11662026-09-16 10:26:05.937 UTC [37057] ERROR: relation "goose_db_version" does not exist at character 3611672026-09-16 10:26:05.937 UTC [37057] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11682026/09/16 10:26:06 WARN Rate limiter enabled after throttle name=s3-test rate=511692026/09/16 10:26:06 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."1170=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle1171 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=101172 throttle_test.go:215: Rate limiter: enabled=true, rate=5.001173--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (6.24s)1174=== CONT TestUploadHandlersRejectInvalidKeys1175=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1176=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1177=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1178=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1179=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1180=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1181=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1182=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1183=== CONT TestCompleteMultipartUpload_ErrorButObjectExists11842026/09/16 10:26:06 INFO Received uploads request method=POST path=/api/pending_closures11852026/09/16 10:26:06 INFO Received uploads request method=POST path=/api/pending_closures11862026/09/16 10:26:06 INFO Received uploads request method=POST path=/api/pending_closures11872026/09/16 10:26:06 OK 20241026095416_initial_model.sql (188.12ms)11882026-09-16 10:26:06.197 UTC [37060] ERROR: relation "goose_db_version" does not exist at character 3611892026-09-16 10:26:06.197 UTC [37060] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11902026/09/16 10:26:06 OK 20251210153512_drop_unused_gin_index.sql (57.43ms)11912026/09/16 10:26:06 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=01192=== NAME TestPinProtectsFromGC1193 client_integration_test.go:711: Pin successfully protected closure from garbage collection11942026/09/16 10:26:06 OK 20251218171726_add_pins.sql (34.76ms)1195--- PASS: TestPinProtectsFromGC (4.09s)1196=== CONT TestUploadHandlersRejectOversizedBody11972026/09/16 10:26:06 OK 20260628120000_add_object_size_and_stats.sql (43.37ms)1198=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure1199=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure1200=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart1201=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart1202=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts1203=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts1204=== CONT TestGracefulShutdownDrainsInflight12052026/09/16 10:26:06 INFO Starting HTTP server address=127.0.0.1:5549012062026/09/16 10:26:06 INFO Shutdown signal received, draining in-flight requests timeout=10s1207--- PASS: TestGracefulShutdownDrainsInflight (0.07s)1208=== CONT TestMetricsInventory12092026/09/16 10:26:06 OK 20260905000000_add_claims.sql (98ms)12102026/09/16 10:26:06 goose: successfully migrated database to version: 2026090500000012112026/09/16 10:26:06 OK 1_commit_pending_closure.sql (2.57ms)12122026/09/16 10:26:06 OK 2_object_stats_trigger.sql (371.96µs)12132026/09/16 10:26:06 goose: up to current file version: 212142026-09-16 10:26:06.454 UTC [37061] ERROR: relation "goose_db_version" does not exist at character 3612152026-09-16 10:26:06.454 UTC [37061] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12162026/09/16 10:26:06 OK 20241026095416_initial_model.sql (183.12ms)12172026/09/16 10:26:06 OK 20251210153512_drop_unused_gin_index.sql (7.39ms)12182026/09/16 10:26:06 OK 20251218171726_add_pins.sql (59.11ms)12192026/09/16 10:26:06 OK 20260628120000_add_object_size_and_stats.sql (39.43ms)12202026/09/16 10:26:06 OK 20260905000000_add_claims.sql (78.72ms)12212026/09/16 10:26:06 goose: successfully migrated database to version: 2026090500000012222026/09/16 10:26:06 OK 1_commit_pending_closure.sql (8.35ms)12232026/09/16 10:26:06 OK 2_object_stats_trigger.sql (447.04µs)12242026/09/16 10:26:06 goose: up to current file version: 212252026/09/16 10:26:06 INFO Received uploads request method=POST path=/api/pending_closures12262026/09/16 10:26:06 OK 20241026095416_initial_model.sql (258.48ms)12272026/09/16 10:26:06 OK 20251210153512_drop_unused_gin_index.sql (12.65ms)12282026/09/16 10:26:06 OK 20251218171726_add_pins.sql (46.94ms)12292026/09/16 10:26:06 INFO Received uploads request method=POST path=/api/pending_closures12302026/09/16 10:26:06 OK 20260628120000_add_object_size_and_stats.sql (45.89ms)12312026-09-16 10:26:06.916 UTC [37064] ERROR: relation "goose_db_version" does not exist at character 3612322026-09-16 10:26:06.916 UTC [37064] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12332026/09/16 10:26:06 OK 20260905000000_add_claims.sql (51.88ms)12342026/09/16 10:26:06 goose: successfully migrated database to version: 2026090500000012352026/09/16 10:26:06 OK 1_commit_pending_closure.sql (9.2ms)12362026/09/16 10:26:06 OK 2_object_stats_trigger.sql (594.42µs)12372026/09/16 10:26:06 goose: up to current file version: 21238--- PASS: TestReadRedirectUsesPublicS3URL (2.30s)1239=== CONT TestNARDeduplicationMetadataUploadBug12402026/09/16 10:26:07 OK 20241026095416_initial_model.sql (307.5ms)12412026/09/16 10:26:07 OK 20251210153512_drop_unused_gin_index.sql (21.17ms)12422026-09-16 10:26:07.336 UTC [37067] ERROR: relation "goose_db_version" does not exist at character 3612432026-09-16 10:26:07.336 UTC [37067] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12442026/09/16 10:26:07 OK 20251218171726_add_pins.sql (42.32ms)12452026/09/16 10:26:07 OK 20260628120000_add_object_size_and_stats.sql (57.57ms)12462026/09/16 10:26:07 INFO Received uploads request method=POST path=/api/pending_closures12472026/09/16 10:26:07 OK 20260905000000_add_claims.sql (91.25ms)12482026/09/16 10:26:07 goose: successfully migrated database to version: 2026090500000012492026/09/16 10:26:07 OK 1_commit_pending_closure.sql (3.9ms)12502026/09/16 10:26:07 OK 2_object_stats_trigger.sql (610.83µs)12512026/09/16 10:26:07 goose: up to current file version: 212522026/09/16 10:26:07 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst12532026/09/16 10:26:07 INFO Received uploads request method=POST path=/api/pending_closures1254--- PASS: TestPresignedUploadRegisteredBeforeCommit (2.51s)1255=== CONT TestCreatePendingClosureRejectsOversizedNAR12562026/09/16 10:26:07 INFO Received uploads request method=POST path=/api/pending_closures1257--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)1258=== CONT TestCacheConfigHandlerMaxNarSize1259--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)1260=== CONT TestGenerateLandingPage1261--- PASS: TestGenerateLandingPage (0.00s)1262=== CONT TestService_readinessHandler12632026/09/16 10:26:07 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12642026/09/16 10:26:07 OK 20241026095416_initial_model.sql (320.96ms)12652026/09/16 10:26:07 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=MGI0NDE3ZTYtYjdlMy00NTZmLTkxYTctYjE3NGY3YzNjMzEzLmM2YThkY2RlLTYyY2QtNDhjNC05NTBiLWNlN2NmNWQ3Yzg5N3gxNzg5NTU0MzY1OTExNDExMDAw parts=1012662026/09/16 10:26:07 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete12672026/09/16 10:26:07 OK 20251210153512_drop_unused_gin_index.sql (16.4ms)12682026/09/16 10:26:07 INFO Completed upload id=112692026/09/16 10:26:07 INFO Received uploads request method=POST path=/api/pending_closures12702026/09/16 10:26:07 INFO Received uploads request method=POST path=/api/pending_closures12712026/09/16 10:26:07 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo12722026/09/16 10:26:07 WARN Found objects in DB but missing from S3, will re-upload count=11273--- PASS: TestService_verifyS3Integrity (3.17s)1274=== CONT TestService_healthCheckHandler12752026/09/16 10:26:07 OK 20251218171726_add_pins.sql (45.24ms)12762026/09/16 10:26:07 OK 20260628120000_add_object_size_and_stats.sql (49.47ms)12772026/09/16 10:26:07 OK 20260905000000_add_claims.sql (85.21ms)12782026/09/16 10:26:07 goose: successfully migrated database to version: 2026090500000012792026/09/16 10:26:07 OK 1_commit_pending_closure.sql (9.82ms)12802026/09/16 10:26:07 OK 2_object_stats_trigger.sql (628.83µs)12812026/09/16 10:26:07 goose: up to current file version: 21282--- PASS: TestReadProxyRangeRequest (2.79s)1283=== CONT TestService_ReadAuthMiddleware12842026/09/16 10:26:08 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12852026/09/16 10:26:08 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=MGI0NDE3ZTYtYjdlMy00NTZmLTkxYTctYjE3NGY3YzNjMzEzLmUzODI4ZjVkLTVjMWQtNDY2Ny1hYTU0LTk5YmI5ZGVjNjlhM3gxNzg5NTU0MzY2MjQ5NTQxMDAw parts=1012862026/09/16 10:26:08 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete12872026/09/16 10:26:08 INFO Completed upload id=112882026/09/16 10:26:08 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000012892026/09/16 10:26:08 INFO Received uploads request method=POST path=/api/pending_closures12902026/09/16 10:26:08 INFO Starting cleanup of old closures method=DELETE path=/api/closures12912026/09/16 10:26:08 INFO Aborted multipart uploads count=012922026/09/16 10:26:08 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=012932026/09/16 10:26:08 INFO Vacuumed table table=pending_closures12942026/09/16 10:26:08 INFO Vacuumed table table=pending_objects12952026/09/16 10:26:08 INFO Vacuumed table table=multipart_uploads12962026/09/16 10:26:08 INFO Received uploads request method=POST path=/api/pending_closures12972026/09/16 10:26:08 INFO Vacuumed table table=closures12982026/09/16 10:26:08 INFO Vacuumed table table=objects12992026/09/16 10:26:08 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001300--- PASS: TestService_createPendingClosureHandler (3.79s)1301=== CONT TestClientMultipleUploads13022026-09-16 10:26:08.445 UTC [37078] ERROR: relation "goose_db_version" does not exist at character 3613032026-09-16 10:26:08.445 UTC [37078] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13042026-09-16 10:26:08.738 UTC [37081] ERROR: relation "goose_db_version" does not exist at character 3613052026-09-16 10:26:08.738 UTC [37081] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13062026/09/16 10:26:08 OK 20241026095416_initial_model.sql (248.34ms)13072026/09/16 10:26:08 OK 20251210153512_drop_unused_gin_index.sql (8.96ms)13082026/09/16 10:26:08 OK 20251218171726_add_pins.sql (26ms)13092026/09/16 10:26:08 OK 20260628120000_add_object_size_and_stats.sql (37.56ms)13102026/09/16 10:26:08 OK 20260905000000_add_claims.sql (65.15ms)13112026/09/16 10:26:08 goose: successfully migrated database to version: 2026090500000013122026/09/16 10:26:08 OK 1_commit_pending_closure.sql (12.96ms)13132026/09/16 10:26:08 OK 2_object_stats_trigger.sql (733.21µs)13142026/09/16 10:26:08 goose: up to current file version: 213152026/09/16 10:26:08 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13162026/09/16 10:26:09 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=MGI0NDE3ZTYtYjdlMy00NTZmLTkxYTctYjE3NGY3YzNjMzEzLjQ2ZGEwYzhkLTM5YjMtNDJhOS1iOWQyLWMwZTQxNjM0ZmYxNHgxNzg5NTU0MzY2ODAyMDMxMDAw parts=121317--- PASS: TestRedundantMultipartUpload (4.22s)1318=== CONT TestService_RequireScope_OIDC13192026/09/16 10:26:09 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:55518/oidc13202026/09/16 10:26:09 OK 20241026095416_initial_model.sql (239.19ms)13212026/09/16 10:26:09 OK 20251210153512_drop_unused_gin_index.sql (9.24ms)13222026/09/16 10:26:09 OK 20251218171726_add_pins.sql (66.08ms)13232026/09/16 10:26:09 OK 20260628120000_add_object_size_and_stats.sql (41.63ms)13242026/09/16 10:26:09 OK 20260905000000_add_claims.sql (81.33ms)13252026/09/16 10:26:09 goose: successfully migrated database to version: 2026090500000013262026/09/16 10:26:09 OK 1_commit_pending_closure.sql (3.3ms)13272026/09/16 10:26:09 OK 2_object_stats_trigger.sql (1.3ms)13282026/09/16 10:26:09 goose: up to current file version: 21329--- PASS: TestReadRedirectKeepsNarinfoProxied (3.71s)1330=== CONT TestService_AuthMiddleware_OIDC13312026/09/16 10:26:09 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:55524/oidc13322026-09-16 10:26:09.529 UTC [37086] ERROR: relation "goose_db_version" does not exist at character 3613332026-09-16 10:26:09.529 UTC [37086] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13342026/09/16 10:26:09 INFO Received uploads request method=POST path=/api/pending_closures13352026/09/16 10:26:09 OK 20241026095416_initial_model.sql (243.22ms)13362026/09/16 10:26:09 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13372026/09/16 10:26:09 OK 20251210153512_drop_unused_gin_index.sql (6.68ms)13382026-09-16 10:26:09.891 UTC [37087] ERROR: relation "goose_db_version" does not exist at character 3613392026-09-16 10:26:09.891 UTC [37087] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13402026/09/16 10:26:09 OK 20251218171726_add_pins.sql (10.22ms)13412026/09/16 10:26:09 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=MGI0NDE3ZTYtYjdlMy00NTZmLTkxYTctYjE3NGY3YzNjMzEzLjkwY2UzNTYxLWRjNGMtNDgzZS1iMWNjLTdiZjcyMmNlYzg3YXgxNzg5NTU0MzY5NjMxMDIxMDAw13422026/09/16 10:26:09 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=MGI0NDE3ZTYtYjdlMy00NTZmLTkxYTctYjE3NGY3YzNjMzEzLjkwY2UzNTYxLWRjNGMtNDgzZS1iMWNjLTdiZjcyMmNlYzg3YXgxNzg5NTU0MzY5NjMxMDIxMDAw parts=11343--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (3.85s)1344=== CONT TestGCTaskStore_GetReturnsLatest1345--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)1346=== CONT TestService_AuthMiddleware_MTLSBoundSubjects13472026/09/16 10:26:09 OK 20260628120000_add_object_size_and_stats.sql (10.2ms)13482026/09/16 10:26:09 OK 20260905000000_add_claims.sql (13.9ms)13492026/09/16 10:26:09 goose: successfully migrated database to version: 2026090500000013502026/09/16 10:26:09 OK 1_commit_pending_closure.sql (1.95ms)13512026/09/16 10:26:09 OK 2_object_stats_trigger.sql (333.58µs)13522026/09/16 10:26:09 goose: up to current file version: 213532026-09-16 10:26:09.986 UTC [37089] ERROR: relation "goose_db_version" does not exist at character 3613542026-09-16 10:26:09.986 UTC [37089] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13552026-09-16 10:26:10.017 UTC [37091] ERROR: relation "goose_db_version" does not exist at character 3613562026-09-16 10:26:10.017 UTC [37091] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13572026/09/16 10:26:10 OK 20241026095416_initial_model.sql (119.38ms)13582026/09/16 10:26:10 OK 20251210153512_drop_unused_gin_index.sql (6.94ms)13592026/09/16 10:26:10 OK 20251218171726_add_pins.sql (28.65ms)13602026/09/16 10:26:10 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13612026-09-16 10:26:10.109 UTC [37092] ERROR: relation "goose_db_version" does not exist at character 3613622026-09-16 10:26:10.109 UTC [37092] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13632026/09/16 10:26:10 OK 20260628120000_add_object_size_and_stats.sql (47.2ms)13642026/09/16 10:26:10 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=MGI0NDE3ZTYtYjdlMy00NTZmLTkxYTctYjE3NGY3YzNjMzEzLmNjNDM1ZDlmLWE3ZWUtNDg3Mi1hZjU2LTkzMWUzNmE3YWVhYXgxNzg5NTU0MzY4MzU0MTE5MDAw parts=1213652026/09/16 10:26:10 INFO Received uploads request method=POST path=/api/pending_closures1366--- PASS: TestCompletedNarNotReofferedAcrossClosures (4.87s)1367=== CONT TestGCTaskStore_Fail1368--- PASS: TestGCTaskStore_Fail (0.00s)1369=== CONT TestService_AuthMiddleware_MTLSProxyHeader13702026/09/16 10:26:10 OK 20260905000000_add_claims.sql (54.07ms)13712026/09/16 10:26:10 goose: successfully migrated database to version: 2026090500000013722026/09/16 10:26:10 OK 1_commit_pending_closure.sql (5.48ms)13732026/09/16 10:26:10 OK 20241026095416_initial_model.sql (160.03ms)13742026/09/16 10:26:10 OK 2_object_stats_trigger.sql (1.67ms)13752026/09/16 10:26:10 goose: up to current file version: 213762026/09/16 10:26:10 OK 20241026095416_initial_model.sql (138.3ms)13772026/09/16 10:26:10 OK 20251210153512_drop_unused_gin_index.sql (2.13ms)13782026/09/16 10:26:10 OK 20251210153512_drop_unused_gin_index.sql (1.43ms)13792026/09/16 10:26:10 OK 20251218171726_add_pins.sql (2.09ms)13802026/09/16 10:26:10 OK 20251218171726_add_pins.sql (1.98ms)1381--- PASS: TestMetricsInventory (3.80s)1382=== CONT TestGCTaskStore_PhaseUpdates1383--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)1384=== CONT TestClientIntegration13852026/09/16 10:26:10 OK 20260628120000_add_object_size_and_stats.sql (27.8ms)13862026/09/16 10:26:10 OK 20260628120000_add_object_size_and_stats.sql (28.06ms)13872026/09/16 10:26:10 OK 20260905000000_add_claims.sql (10.87ms)13882026/09/16 10:26:10 goose: successfully migrated database to version: 2026090500000013892026/09/16 10:26:10 OK 20241026095416_initial_model.sql (55.39ms)13902026/09/16 10:26:10 OK 20260905000000_add_claims.sql (10.06ms)13912026/09/16 10:26:10 goose: successfully migrated database to version: 2026090500000013922026/09/16 10:26:10 OK 1_commit_pending_closure.sql (4.13ms)13932026/09/16 10:26:10 OK 1_commit_pending_closure.sql (4.25ms)13942026/09/16 10:26:10 OK 2_object_stats_trigger.sql (336.25µs)13952026/09/16 10:26:10 goose: up to current file version: 213962026/09/16 10:26:10 OK 2_object_stats_trigger.sql (345.46µs)13972026/09/16 10:26:10 goose: up to current file version: 213982026/09/16 10:26:10 OK 20251210153512_drop_unused_gin_index.sql (10.57ms)13992026/09/16 10:26:10 OK 20251218171726_add_pins.sql (10.15ms)14002026-09-16 10:26:10.278 UTC [37097] ERROR: relation "goose_db_version" does not exist at character 3614012026-09-16 10:26:10.278 UTC [37097] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14022026/09/16 10:26:10 OK 20260628120000_add_object_size_and_stats.sql (19ms)14032026/09/16 10:26:10 OK 20260905000000_add_claims.sql (15.18ms)14042026/09/16 10:26:10 goose: successfully migrated database to version: 2026090500000014052026/09/16 10:26:10 OK 1_commit_pending_closure.sql (7.07ms)14062026/09/16 10:26:10 OK 2_object_stats_trigger.sql (373.67µs)14072026/09/16 10:26:10 goose: up to current file version: 214082026/09/16 10:26:10 OK 20241026095416_initial_model.sql (72.08ms)14092026/09/16 10:26:10 OK 20251210153512_drop_unused_gin_index.sql (8.23ms)14102026/09/16 10:26:10 OK 20251218171726_add_pins.sql (10.26ms)14112026/09/16 10:26:10 OK 20260628120000_add_object_size_and_stats.sql (46.96ms)14122026/09/16 10:26:10 OK 20260905000000_add_claims.sql (11.23ms)14132026/09/16 10:26:10 goose: successfully migrated database to version: 2026090500000014142026/09/16 10:26:10 OK 1_commit_pending_closure.sql (12.29ms)14152026/09/16 10:26:10 OK 2_object_stats_trigger.sql (755.92µs)14162026/09/16 10:26:10 goose: up to current file version: 21417=== NAME TestNARDeduplicationMetadataUploadBug1418 metadata_upload_test.go:48: First store path: /nix/var/nix/builds/nix-36727-1823504073/TestNARDeduplicationMetadataUploadBug463814093/001/store/kl43l46pfv96f8wl0jdf53k1l44phdrs-file1.txt14192026-09-16 10:26:10.537 UTC [37101] ERROR: relation "goose_db_version" does not exist at character 3614202026-09-16 10:26:10.537 UTC [37101] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1421--- PASS: TestService_healthCheckHandler (2.81s)1422=== CONT TestServerTLSConfig/not_a_PEM_file1423=== CONT TestGCTaskStore_CompletedAllowsNewTask1424--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)1425=== CONT TestServerTLSConfig/missing_CA_file1426=== CONT TestClaim_StreamsThroughServer1427--- PASS: TestServerTLSConfig (0.00s)1428 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1429 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)1430 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)14312026/09/16 10:26:10 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"14322026/09/16 10:26:10 OK 20241026095416_initial_model.sql (46.68ms)14332026/09/16 10:26:10 OK 20251210153512_drop_unused_gin_index.sql (640.42µs)14342026/09/16 10:26:10 OK 20251218171726_add_pins.sql (9.63ms)14352026-09-16 10:26:10.632 UTC [37108] ERROR: relation "goose_db_version" does not exist at character 3614362026-09-16 10:26:10.632 UTC [37108] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14372026/09/16 10:26:10 INFO Received uploads request method=POST path=/api/pending_closures14382026/09/16 10:26:10 OK 20260628120000_add_object_size_and_stats.sql (15.21ms)14392026/09/16 10:26:10 OK 20260905000000_add_claims.sql (9.79ms)14402026/09/16 10:26:10 goose: successfully migrated database to version: 2026090500000014412026/09/16 10:26:10 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)14422026/09/16 10:26:10 INFO Uploading kl43l46pfv96f8wl0jdf53k1l44phdrs-file1.txt (160B)14432026/09/16 10:26:10 OK 1_commit_pending_closure.sql (1.31ms)14442026/09/16 10:26:10 OK 2_object_stats_trigger.sql (243.42µs)14452026/09/16 10:26:10 goose: up to current file version: 214462026/09/16 10:26:10 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"14472026/09/16 10:26:10 WARN Failed to register uploaded object key=kl43l46pfv96f8wl0jdf53k1l44phdrs.ls error="server returned 404: 404 page not found\n"14482026/09/16 10:26:10 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign14492026/09/16 10:26:10 INFO Signed narinfos id=1 count=114502026/09/16 10:26:10 INFO Uploading 1 narinfos14512026/09/16 10:26:10 WARN Failed to register uploaded object key=kl43l46pfv96f8wl0jdf53k1l44phdrs.narinfo error="server returned 404: 404 page not found\n"14522026/09/16 10:26:10 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete14532026/09/16 10:26:10 INFO Completed upload id=114542026/09/16 10:26:10 INFO Upload complete. (142ms)1455=== NAME TestNARDeduplicationMetadataUploadBug1456 metadata_upload_test.go:54: Retrieved narinfo from S3:1457 StorePath: /nix/var/nix/builds/nix-36727-1823504073/TestNARDeduplicationMetadataUploadBug463814093/001/store/kl43l46pfv96f8wl0jdf53k1l44phdrs-file1.txt1458 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1459 Compression: zstd1460 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1461 NarSize: 1601462 References: 1463 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1464 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1465 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1466 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}14672026/09/16 10:26:10 OK 20241026095416_initial_model.sql (64.26ms)14682026/09/16 10:26:10 OK 20251210153512_drop_unused_gin_index.sql (12.89ms)14692026/09/16 10:26:10 OK 20251218171726_add_pins.sql (14.57ms)14702026/09/16 10:26:10 WARN readiness check failed error="closed pool"1471--- PASS: TestService_readinessHandler (3.15s)1472=== CONT TestClientCADerivations1473=== NAME TestNARDeduplicationMetadataUploadBug1474 metadata_upload_test.go:64: Second store path (same content): /nix/var/nix/builds/nix-36727-1823504073/TestNARDeduplicationMetadataUploadBug463814093/001/store/297j9nhad4ihwv98rfh2nb2d7gpjc0s5-file2.txt14752026/09/16 10:26:10 OK 20260628120000_add_object_size_and_stats.sql (3.19ms)14762026/09/16 10:26:10 OK 20260905000000_add_claims.sql (11.65ms)14772026/09/16 10:26:10 goose: successfully migrated database to version: 2026090500000014782026/09/16 10:26:10 OK 1_commit_pending_closure.sql (6.99ms)14792026/09/16 10:26:10 OK 2_object_stats_trigger.sql (306.13µs)14802026/09/16 10:26:10 goose: up to current file version: 214812026-09-16 10:26:10.805 UTC [37117] ERROR: relation "goose_db_version" does not exist at character 3614822026-09-16 10:26:10.805 UTC [37117] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14832026/09/16 10:26:10 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"14842026/09/16 10:26:10 INFO Received uploads request method=POST path=/api/pending_closures14852026/09/16 10:26:10 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)14862026/09/16 10:26:10 WARN Failed to register uploaded object key=297j9nhad4ihwv98rfh2nb2d7gpjc0s5.ls error="server returned 404: 404 page not found\n"14872026/09/16 10:26:10 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign14882026/09/16 10:26:10 INFO Signed narinfos id=2 count=114892026/09/16 10:26:10 INFO Uploading 1 narinfos14902026/09/16 10:26:10 WARN Failed to register uploaded object key=297j9nhad4ihwv98rfh2nb2d7gpjc0s5.narinfo error="server returned 404: 404 page not found\n"14912026/09/16 10:26:10 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete14922026/09/16 10:26:10 INFO Completed upload id=214932026/09/16 10:26:10 INFO Upload complete. (93ms)1494 metadata_upload_test.go:76: Retrieved narinfo from S3:1495 StorePath: /nix/var/nix/builds/nix-36727-1823504073/TestNARDeduplicationMetadataUploadBug463814093/001/store/297j9nhad4ihwv98rfh2nb2d7gpjc0s5-file2.txt1496 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1497 Compression: zstd1498 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1499 NarSize: 1601500 References: 1501 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1502 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1503 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1504 {"version":1,"root":{"type":"regular","size":44}}15052026/09/16 10:26:10 OK 20241026095416_initial_model.sql (56.46ms)15062026/09/16 10:26:10 OK 20251210153512_drop_unused_gin_index.sql (13.89ms)15072026/09/16 10:26:10 OK 20251218171726_add_pins.sql (11.75ms)1508--- PASS: TestNARDeduplicationMetadataUploadBug (3.72s)1509=== CONT TestResurrectedObjectNotDeleted1510--- PASS: TestService_ReadAuthMiddleware (2.94s)1511=== CONT TestReadProxyNarinfo15122026-09-16 10:26:10.916 UTC [37123] ERROR: relation "goose_db_version" does not exist at character 3615132026-09-16 10:26:10.916 UTC [37123] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15142026/09/16 10:26:10 OK 20260628120000_add_object_size_and_stats.sql (18.88ms)15152026/09/16 10:26:10 OK 20260905000000_add_claims.sql (24.11ms)15162026/09/16 10:26:10 goose: successfully migrated database to version: 2026090500000015172026/09/16 10:26:10 OK 1_commit_pending_closure.sql (1.11ms)15182026/09/16 10:26:10 OK 2_object_stats_trigger.sql (231.96µs)15192026/09/16 10:26:10 goose: up to current file version: 215202026/09/16 10:26:10 OK 20241026095416_initial_model.sql (49.71ms)15212026-09-16 10:26:11.000 UTC [37126] ERROR: relation "goose_db_version" does not exist at character 3615222026-09-16 10:26:11.000 UTC [37126] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15232026/09/16 10:26:11 OK 20251210153512_drop_unused_gin_index.sql (1.96ms)15242026/09/16 10:26:11 OK 20251218171726_add_pins.sql (39.2ms)15252026/09/16 10:26:11 OK 20260628120000_add_object_size_and_stats.sql (23.04ms)15262026/09/16 10:26:11 OK 20260905000000_add_claims.sql (20.75ms)15272026/09/16 10:26:11 goose: successfully migrated database to version: 2026090500000015282026/09/16 10:26:11 OK 1_commit_pending_closure.sql (1.91ms)15292026/09/16 10:26:11 OK 2_object_stats_trigger.sql (494.42µs)15302026/09/16 10:26:11 goose: up to current file version: 215312026/09/16 10:26:11 OK 20241026095416_initial_model.sql (62.79ms)15322026/09/16 10:26:11 OK 20251210153512_drop_unused_gin_index.sql (1.8ms)15332026/09/16 10:26:11 OK 20251218171726_add_pins.sql (10.68ms)15342026/09/16 10:26:11 OK 20260628120000_add_object_size_and_stats.sql (12.32ms)15352026/09/16 10:26:11 OK 20260905000000_add_claims.sql (17.66ms)15362026/09/16 10:26:11 goose: successfully migrated database to version: 2026090500000015372026/09/16 10:26:11 OK 1_commit_pending_closure.sql (11.36ms)15382026/09/16 10:26:11 OK 2_object_stats_trigger.sql (367.67µs)15392026/09/16 10:26:11 goose: up to current file version: 21540=== NAME TestClientMultipleUploads1541 client_integration_test.go:339: Created store path 0: /nix/var/nix/builds/nix-36727-1823504073/TestClientMultipleUploads3400436924/001/store/k4gnhr73mkk538a960zc91j48836jsjf-test-file-0.txt1542 client_integration_test.go:339: Created store path 1: /nix/var/nix/builds/nix-36727-1823504073/TestClientMultipleUploads3400436924/001/store/d958s846d6fabyrkdfbdah5ll78xggln-test-file-1.txt1543=== RUN TestService_RequireScope_OIDC/builder_may_write1544=== PAUSE TestService_RequireScope_OIDC/builder_may_write1545=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1546=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1547=== RUN TestService_RequireScope_OIDC/ops_may_admin1548=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1549=== RUN TestService_RequireScope_OIDC/ops_may_not_write1550=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1551=== RUN TestService_RequireScope_OIDC/reader_may_not_write1552=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1553=== RUN TestService_RequireScope_OIDC/static_token_may_admin1554=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1555=== RUN TestService_RequireScope_OIDC/static_token_may_write1556=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1557=== RUN TestService_RequireScope_OIDC/reader_may_read1558=== PAUSE TestService_RequireScope_OIDC/reader_may_read1559=== RUN TestService_RequireScope_OIDC/writer_implies_read1560=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1561=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1562=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1563=== CONT TestIsValidCachePath1564=== RUN TestIsValidCachePath/narinfo1565=== PAUSE TestIsValidCachePath/narinfo1566=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars1567=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars1568=== RUN TestIsValidCachePath/nar_zst1569=== PAUSE TestIsValidCachePath/nar_zst1570=== RUN TestIsValidCachePath/nar_xz1571=== PAUSE TestIsValidCachePath/nar_xz1572=== RUN TestIsValidCachePath/nar_bz21573=== PAUSE TestIsValidCachePath/nar_bz21574=== RUN TestIsValidCachePath/nar_uncompressed1575=== PAUSE TestIsValidCachePath/nar_uncompressed1576=== RUN TestIsValidCachePath/ls1577=== PAUSE TestIsValidCachePath/ls1578=== RUN TestIsValidCachePath/log1579=== PAUSE TestIsValidCachePath/log1580=== RUN TestIsValidCachePath/realisation1581=== PAUSE TestIsValidCachePath/realisation1582=== RUN TestIsValidCachePath/nix-cache-info1583=== PAUSE TestIsValidCachePath/nix-cache-info1584=== RUN TestIsValidCachePath/index.html1585=== PAUSE TestIsValidCachePath/index.html1586=== RUN TestIsValidCachePath/traversal_parent1587=== PAUSE TestIsValidCachePath/traversal_parent1588=== RUN TestIsValidCachePath/traversal_in_middle1589=== PAUSE TestIsValidCachePath/traversal_in_middle1590=== RUN TestIsValidCachePath/invalid_char_e1591=== PAUSE TestIsValidCachePath/invalid_char_e1592=== RUN TestIsValidCachePath/invalid_char_u1593=== PAUSE TestIsValidCachePath/invalid_char_u1594=== RUN TestIsValidCachePath/random_path1595=== PAUSE TestIsValidCachePath/random_path1596=== RUN TestIsValidCachePath/empty1597=== PAUSE TestIsValidCachePath/empty1598=== RUN TestIsValidCachePath/leading_slash1599=== PAUSE TestIsValidCachePath/leading_slash1600=== RUN TestIsValidCachePath/wrong_extension1601=== PAUSE TestIsValidCachePath/wrong_extension1602=== RUN TestIsValidCachePath/short_hash1603=== PAUSE TestIsValidCachePath/short_hash1604=== CONT TestParseSingleRange1605=== RUN TestParseSingleRange/none1606=== PAUSE TestParseSingleRange/none1607=== RUN TestParseSingleRange/unknown_unit1608=== PAUSE TestParseSingleRange/unknown_unit1609=== RUN TestParseSingleRange/multi-range_ignored1610=== PAUSE TestParseSingleRange/multi-range_ignored1611=== RUN TestParseSingleRange/malformed_no_dash1612=== PAUSE TestParseSingleRange/malformed_no_dash1613=== RUN TestParseSingleRange/malformed_both_empty1614=== PAUSE TestParseSingleRange/malformed_both_empty1615=== RUN TestParseSingleRange/malformed_end_before_start1616=== PAUSE TestParseSingleRange/malformed_end_before_start1617=== RUN TestParseSingleRange/closed1618=== PAUSE TestParseSingleRange/closed1619=== RUN TestParseSingleRange/open-ended1620=== PAUSE TestParseSingleRange/open-ended1621=== RUN TestParseSingleRange/end_clamped_to_size1622=== PAUSE TestParseSingleRange/end_clamped_to_size1623=== RUN TestParseSingleRange/suffix1624=== PAUSE TestParseSingleRange/suffix1625=== RUN TestParseSingleRange/suffix_exceeds_size1626=== PAUSE TestParseSingleRange/suffix_exceeds_size1627=== RUN TestParseSingleRange/single_byte1628=== PAUSE TestParseSingleRange/single_byte1629=== RUN TestParseSingleRange/start_past_EOF1630=== PAUSE TestParseSingleRange/start_past_EOF1631=== RUN TestParseSingleRange/start_far_past_EOF1632=== PAUSE TestParseSingleRange/start_far_past_EOF1633=== CONT TestClaim_InputsTouched1634=== NAME TestClientMultipleUploads1635 client_integration_test.go:339: Created store path 2: /nix/var/nix/builds/nix-36727-1823504073/TestClientMultipleUploads3400436924/001/store/rry19cs084015bdssms9xm76k98rbgsc-test-file-2.txt16362026-09-16 10:26:11.293 UTC [37136] ERROR: relation "goose_db_version" does not exist at character 3616372026-09-16 10:26:11.293 UTC [37136] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16382026/09/16 10:26:11 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"16392026/09/16 10:26:11 OK 20241026095416_initial_model.sql (52.29ms)16402026/09/16 10:26:11 OK 20251210153512_drop_unused_gin_index.sql (7.51ms)16412026/09/16 10:26:11 OK 20251218171726_add_pins.sql (13ms)1642=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1643=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1644=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1645=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1646=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1647=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1648=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1649=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1650=== CONT TestOrphanedObjectsGC16512026/09/16 10:26:11 INFO Received uploads request method=POST path=/api/pending_closures16522026/09/16 10:26:11 OK 20260628120000_add_object_size_and_stats.sql (10.15ms)16532026/09/16 10:26:11 OK 20260905000000_add_claims.sql (4.27ms)16542026/09/16 10:26:11 goose: successfully migrated database to version: 2026090500000016552026/09/16 10:26:11 OK 1_commit_pending_closure.sql (870.13µs)16562026/09/16 10:26:11 OK 2_object_stats_trigger.sql (237.88µs)16572026/09/16 10:26:11 goose: up to current file version: 216582026/09/16 10:26:11 INFO Received uploads request method=POST path=/api/pending_closures16592026/09/16 10:26:11 INFO Received uploads request method=POST path=/api/pending_closures16602026/09/16 10:26:11 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)16612026/09/16 10:26:11 INFO Uploading rry19cs084015bdssms9xm76k98rbgsc-test-file-2.txt (160B)16622026/09/16 10:26:11 INFO Uploading k4gnhr73mkk538a960zc91j48836jsjf-test-file-0.txt (160B)16632026/09/16 10:26:11 INFO Uploading d958s846d6fabyrkdfbdah5ll78xggln-test-file-1.txt (160B)16642026/09/16 10:26:11 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"16652026/09/16 10:26:11 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"16662026/09/16 10:26:11 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"16672026/09/16 10:26:11 WARN Failed to register uploaded object key=k4gnhr73mkk538a960zc91j48836jsjf.ls error="server returned 404: 404 page not found\n"16682026/09/16 10:26:11 WARN Failed to register uploaded object key=d958s846d6fabyrkdfbdah5ll78xggln.ls error="server returned 404: 404 page not found\n"16692026/09/16 10:26:11 WARN Failed to register uploaded object key=rry19cs084015bdssms9xm76k98rbgsc.ls error="server returned 404: 404 page not found\n"16702026/09/16 10:26:11 INFO Received sign narinfos request method=POST path=/api/pending_closures/3/sign16712026/09/16 10:26:11 INFO Signed narinfos id=3 count=116722026/09/16 10:26:11 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign16732026/09/16 10:26:11 INFO Signed narinfos id=1 count=116742026/09/16 10:26:11 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign16752026/09/16 10:26:11 INFO Signed narinfos id=2 count=116762026/09/16 10:26:11 INFO Uploading 3 narinfos16772026/09/16 10:26:11 WARN Failed to register uploaded object key=d958s846d6fabyrkdfbdah5ll78xggln.narinfo error="server returned 404: 404 page not found\n"16782026/09/16 10:26:11 WARN Failed to register uploaded object key=k4gnhr73mkk538a960zc91j48836jsjf.narinfo error="server returned 404: 404 page not found\n"16792026/09/16 10:26:11 WARN Failed to register uploaded object key=rry19cs084015bdssms9xm76k98rbgsc.narinfo error="server returned 404: 404 page not found\n"16802026/09/16 10:26:11 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete16812026-09-16 10:26:11.449 UTC [37144] ERROR: relation "goose_db_version" does not exist at character 3616822026-09-16 10:26:11.449 UTC [37144] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16832026/09/16 10:26:11 INFO Completed upload id=116842026/09/16 10:26:11 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete16852026/09/16 10:26:11 INFO Completed upload id=216862026/09/16 10:26:11 INFO Received complete upload request method=POST path=/api/pending_closures/3/complete16872026/09/16 10:26:11 INFO Completed upload id=316882026/09/16 10:26:11 INFO Upload complete. (143ms)1689=== NAME TestClientMultipleUploads1690 client_integration_test.go:350: Uploaded 3 paths in 176.015ms1691--- PASS: TestClientMultipleUploads (3.09s)1692=== CONT TestOrphanedObjectsGCStressTest16932026/09/16 10:26:11 OK 20241026095416_initial_model.sql (76.99ms)16942026/09/16 10:26:11 OK 20251210153512_drop_unused_gin_index.sql (13.97ms)16952026/09/16 10:26:11 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"16962026/09/16 10:26:11 WARN mTLS auth: bound subjects configured but subject DN unavailable16972026/09/16 10:26:11 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1698--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (1.67s)1699=== CONT TestObjectStatsTrigger17002026/09/16 10:26:11 OK 20251218171726_add_pins.sql (3.16ms)17012026/09/16 10:26:11 OK 20260628120000_add_object_size_and_stats.sql (21.83ms)17022026/09/16 10:26:11 OK 20260905000000_add_claims.sql (25.43ms)17032026/09/16 10:26:11 goose: successfully migrated database to version: 2026090500000017042026/09/16 10:26:11 OK 1_commit_pending_closure.sql (18.03ms)17052026/09/16 10:26:11 OK 2_object_stats_trigger.sql (324.54µs)17062026/09/16 10:26:11 goose: up to current file version: 217072026-09-16 10:26:11.649 UTC [37149] ERROR: relation "goose_db_version" does not exist at character 3617082026-09-16 10:26:11.649 UTC [37149] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17092026-09-16 10:26:11.680 UTC [37150] ERROR: relation "goose_db_version" does not exist at character 3617102026-09-16 10:26:11.680 UTC [37150] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1711--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (1.57s)1712=== CONT TestIsValidUploadKey1713=== RUN TestIsValidUploadKey/narinfo1714=== PAUSE TestIsValidUploadKey/narinfo1715=== RUN TestIsValidUploadKey/nar_zst1716=== PAUSE TestIsValidUploadKey/nar_zst1717=== RUN TestIsValidUploadKey/nar_xz1718=== PAUSE TestIsValidUploadKey/nar_xz1719=== RUN TestIsValidUploadKey/nar_plain1720=== PAUSE TestIsValidUploadKey/nar_plain1721=== RUN TestIsValidUploadKey/listing1722=== PAUSE TestIsValidUploadKey/listing1723=== RUN TestIsValidUploadKey/build_log1724=== PAUSE TestIsValidUploadKey/build_log1725=== RUN TestIsValidUploadKey/build_log_home-manager_file1726=== PAUSE TestIsValidUploadKey/build_log_home-manager_file1727=== RUN TestIsValidUploadKey/build_log_plus_in_name1728=== PAUSE TestIsValidUploadKey/build_log_plus_in_name1729=== RUN TestIsValidUploadKey/build_log_question_mark1730=== PAUSE TestIsValidUploadKey/build_log_question_mark1731=== RUN TestIsValidUploadKey/build_log_equals1732=== PAUSE TestIsValidUploadKey/build_log_equals1733=== RUN TestIsValidUploadKey/realisation1734=== PAUSE TestIsValidUploadKey/realisation1735=== RUN TestIsValidUploadKey/realisation_plus_in_output1736=== PAUSE TestIsValidUploadKey/realisation_plus_in_output1737=== RUN TestIsValidUploadKey/nix-cache-info1738=== PAUSE TestIsValidUploadKey/nix-cache-info1739=== RUN TestIsValidUploadKey/index.html1740=== PAUSE TestIsValidUploadKey/index.html1741=== RUN TestIsValidUploadKey/narinfo_key,_nar_type1742=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type1743=== RUN TestIsValidUploadKey/nar_key,_narinfo_type1744=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type1745=== RUN TestIsValidUploadKey/listing_key,_narinfo_type1746=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type1747=== RUN TestIsValidUploadKey/traversal1748=== PAUSE TestIsValidUploadKey/traversal1749=== RUN TestIsValidUploadKey/traversal_nar1750=== PAUSE TestIsValidUploadKey/traversal_nar1751=== RUN TestIsValidUploadKey/absolute1752=== PAUSE TestIsValidUploadKey/absolute1753=== RUN TestIsValidUploadKey/empty_key1754=== PAUSE TestIsValidUploadKey/empty_key1755=== RUN TestIsValidUploadKey/unknown_type1756=== PAUSE TestIsValidUploadKey/unknown_type1757=== CONT TestProxyWriteTimeout1758=== RUN TestProxyWriteTimeout/narinfo1759=== PAUSE TestProxyWriteTimeout/narinfo1760=== RUN TestProxyWriteTimeout/1_GiB_nar1761=== PAUSE TestProxyWriteTimeout/1_GiB_nar1762=== RUN TestProxyWriteTimeout/10_GiB_nar1763=== PAUSE TestProxyWriteTimeout/10_GiB_nar1764=== RUN TestProxyWriteTimeout/unknown_size1765=== PAUSE TestProxyWriteTimeout/unknown_size1766=== CONT TestService_ReadScope_PublicByDefault17672026/09/16 10:26:11 OK 20241026095416_initial_model.sql (80.04ms)17682026/09/16 10:26:11 OK 20251210153512_drop_unused_gin_index.sql (2.32ms)17692026/09/16 10:26:11 OK 20241026095416_initial_model.sql (60.27ms)17702026/09/16 10:26:11 OK 20251218171726_add_pins.sql (11.35ms)17712026/09/16 10:26:11 OK 20251210153512_drop_unused_gin_index.sql (7.68ms)17722026/09/16 10:26:11 OK 20260628120000_add_object_size_and_stats.sql (21.09ms)17732026/09/16 10:26:11 OK 20251218171726_add_pins.sql (14.97ms)17742026/09/16 10:26:11 OK 20260905000000_add_claims.sql (10.49ms)17752026/09/16 10:26:11 goose: successfully migrated database to version: 2026090500000017762026/09/16 10:26:11 OK 20260628120000_add_object_size_and_stats.sql (10.68ms)17772026/09/16 10:26:11 OK 1_commit_pending_closure.sql (1.98ms)17782026/09/16 10:26:11 OK 2_object_stats_trigger.sql (368.04µs)17792026/09/16 10:26:11 goose: up to current file version: 217802026/09/16 10:26:11 OK 20260905000000_add_claims.sql (21.24ms)17812026/09/16 10:26:11 goose: successfully migrated database to version: 2026090500000017822026/09/16 10:26:11 OK 1_commit_pending_closure.sql (2.37ms)17832026/09/16 10:26:11 OK 2_object_stats_trigger.sql (417.75µs)17842026/09/16 10:26:11 goose: up to current file version: 217852026-09-16 10:26:12.013 UTC [37155] ERROR: relation "goose_db_version" does not exist at character 3617862026-09-16 10:26:12.013 UTC [37155] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1787=== NAME TestClientIntegration1788 client_integration_test.go:277: Created store path: /nix/var/nix/builds/nix-36727-1823504073/TestClientIntegration1342488000/002/store/gxczw27gvsnhv8xqa0zpjd7rp84wx3ga-test-file.txt17892026/09/16 10:26:12 OK 20241026095416_initial_model.sql (36.57ms)17902026/09/16 10:26:12 OK 20251210153512_drop_unused_gin_index.sql (5.97ms)17912026/09/16 10:26:12 OK 20251218171726_add_pins.sql (2.85ms)17922026/09/16 10:26:12 OK 20260628120000_add_object_size_and_stats.sql (20.97ms)17932026/09/16 10:26:12 OK 20260905000000_add_claims.sql (2.98ms)17942026/09/16 10:26:12 goose: successfully migrated database to version: 2026090500000017952026/09/16 10:26:12 OK 1_commit_pending_closure.sql (1.43ms)17962026/09/16 10:26:12 OK 2_object_stats_trigger.sql (261µs)17972026/09/16 10:26:12 goose: up to current file version: 217982026-09-16 10:26:12.118 UTC [37161] ERROR: relation "goose_db_version" does not exist at character 3617992026-09-16 10:26:12.118 UTC [37161] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18002026/09/16 10:26:12 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"18012026/09/16 10:26:12 INFO Received uploads request method=POST path=/api/pending_closures18022026/09/16 10:26:12 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)18032026/09/16 10:26:12 INFO Uploading gxczw27gvsnhv8xqa0zpjd7rp84wx3ga-test-file.txt (152B)18042026/09/16 10:26:12 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"18052026/09/16 10:26:12 WARN Failed to register uploaded object key=gxczw27gvsnhv8xqa0zpjd7rp84wx3ga.ls error="server returned 404: 404 page not found\n"18062026/09/16 10:26:12 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign18072026/09/16 10:26:12 INFO Signed narinfos id=1 count=118082026/09/16 10:26:12 INFO Uploading 1 narinfos18092026/09/16 10:26:12 OK 20241026095416_initial_model.sql (35.02ms)18102026/09/16 10:26:12 OK 20251210153512_drop_unused_gin_index.sql (6.23ms)18112026/09/16 10:26:12 WARN Failed to register uploaded object key=gxczw27gvsnhv8xqa0zpjd7rp84wx3ga.narinfo error="server returned 404: 404 page not found\n"18122026/09/16 10:26:12 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete18132026/09/16 10:26:12 OK 20251218171726_add_pins.sql (13.08ms)18142026/09/16 10:26:12 INFO Completed upload id=118152026/09/16 10:26:12 INFO Upload complete. (131ms)1816 client_integration_test.go:293: Retrieved narinfo from S3:1817 StorePath: /nix/var/nix/builds/nix-36727-1823504073/TestClientIntegration1342488000/002/store/gxczw27gvsnhv8xqa0zpjd7rp84wx3ga-test-file.txt1818 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1819 Compression: zstd1820 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11821 NarSize: 1521822 References: 1823 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11824 client_integration_test.go:294: Retrieved .ls file from S3 (compressed size: 77 bytes)1825 client_integration_test.go:294: Decompressed .ls content (64 bytes):1826 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1827 client_integration_test.go:297: Testing garbage collection...18282026/09/16 10:26:12 OK 20260628120000_add_object_size_and_stats.sql (7.94ms)18292026/09/16 10:26:12 OK 20260905000000_add_claims.sql (23.43ms)18302026/09/16 10:26:12 goose: successfully migrated database to version: 2026090500000018312026/09/16 10:26:12 OK 1_commit_pending_closure.sql (1.61ms)18322026/09/16 10:26:12 OK 2_object_stats_trigger.sql (517.04µs)18332026/09/16 10:26:12 goose: up to current file version: 218342026/09/16 10:26:12 INFO Starting cleanup of old closures method=DELETE path=/api/closures18352026/09/16 10:26:12 INFO Garbage collection started18362026-09-16 10:26:12.265 UTC [37166] ERROR: relation "goose_db_version" does not exist at character 3618372026-09-16 10:26:12.265 UTC [37166] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18382026/09/16 10:26:12 INFO Aborted multipart uploads count=018392026/09/16 10:26:12 WARN Force mode enabled - objects will be deleted immediately without grace period18402026-09-16 10:26:12.290 UTC [37169] ERROR: relation "goose_db_version" does not exist at character 3618412026-09-16 10:26:12.290 UTC [37169] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18422026/09/16 10:26:12 OK 20241026095416_initial_model.sql (38.13ms)18432026/09/16 10:26:12 OK 20251210153512_drop_unused_gin_index.sql (12.42ms)18442026/09/16 10:26:12 OK 20251218171726_add_pins.sql (6.94ms)18452026/09/16 10:26:12 OK 20260628120000_add_object_size_and_stats.sql (6.59ms)18462026/09/16 10:26:12 OK 20260905000000_add_claims.sql (11.62ms)18472026/09/16 10:26:12 goose: successfully migrated database to version: 2026090500000018482026/09/16 10:26:12 OK 20241026095416_initial_model.sql (50.38ms)18492026/09/16 10:26:12 OK 1_commit_pending_closure.sql (1.18ms)18502026/09/16 10:26:12 OK 2_object_stats_trigger.sql (368.88µs)18512026/09/16 10:26:12 goose: up to current file version: 218522026/09/16 10:26:12 OK 20251210153512_drop_unused_gin_index.sql (6.52ms)18532026/09/16 10:26:12 OK 20251218171726_add_pins.sql (1.89ms)18542026-09-16 10:26:12.368 UTC [37172] ERROR: relation "goose_db_version" does not exist at character 3618552026-09-16 10:26:12.368 UTC [37172] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18562026/09/16 10:26:12 OK 20260628120000_add_object_size_and_stats.sql (21.23ms)18572026/09/16 10:26:12 OK 20260905000000_add_claims.sql (6.53ms)18582026/09/16 10:26:12 goose: successfully migrated database to version: 2026090500000018592026/09/16 10:26:12 OK 1_commit_pending_closure.sql (4.05ms)18602026/09/16 10:26:12 OK 2_object_stats_trigger.sql (216.83µs)18612026/09/16 10:26:12 goose: up to current file version: 21862--- PASS: TestReadProxyNarinfo (1.51s)1863=== CONT TestClientErrorHandling1864=== RUN TestClientErrorHandling/InvalidStorePath1865=== PAUSE TestClientErrorHandling/InvalidStorePath1866=== RUN TestClientErrorHandling/InvalidAuthToken1867=== PAUSE TestClientErrorHandling/InvalidAuthToken1868=== RUN TestClientErrorHandling/ServerNotAvailable1869=== PAUSE TestClientErrorHandling/ServerNotAvailable1870=== CONT TestClientWithDependencies18712026/09/16 10:26:12 OK 20241026095416_initial_model.sql (32.01ms)18722026/09/16 10:26:12 OK 20251210153512_drop_unused_gin_index.sql (852.96µs)18732026/09/16 10:26:12 OK 20251218171726_add_pins.sql (9.49ms)18742026/09/16 10:26:12 OK 20260628120000_add_object_size_and_stats.sql (1.23ms)18752026/09/16 10:26:12 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=018762026/09/16 10:26:12 OK 20260905000000_add_claims.sql (14.59ms)18772026/09/16 10:26:12 goose: successfully migrated database to version: 2026090500000018782026/09/16 10:26:12 OK 1_commit_pending_closure.sql (7.45ms)18792026/09/16 10:26:12 OK 2_object_stats_trigger.sql (299.29µs)18802026/09/16 10:26:12 goose: up to current file version: 218812026/09/16 10:26:12 INFO Vacuumed table table=pending_closures18822026/09/16 10:26:12 INFO Vacuumed table table=pending_objects18832026/09/16 10:26:12 INFO Vacuumed table table=multipart_uploads18842026/09/16 10:26:12 INFO Vacuumed table table=closures18852026/09/16 10:26:12 INFO Vacuumed table table=objects1886=== NAME TestClientCADerivations1887 client_ca_test.go:136: Built CA derivation: /nix/var/nix/builds/nix-36727-1823504073/TestClientCADerivations1134325837/001/store/3dbsk96r5q7wbjda2vzkgys7ww5j5mqq-ca-test1888 client_ca_test.go:139: Found 1 dependencies (including self)1889--- PASS: TestResurrectedObjectNotDeleted (1.67s)1890=== CONT TestResolveDBConnectionString/flag_wins1891=== CONT TestResolveDBConnectionString/PGHOST_allows_empty1892=== CONT TestResolveDBConnectionString/nothing_configured1893=== CONT TestResolveDBConnectionString/missing_file_is_an_error1894=== CONT TestResolveDBConnectionString/file_when_flag_empty1895=== CONT TestCacheConfigHandler/full_config,_no_issuer1896=== CONT TestCacheConfigHandler/no_signing_keys1897=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1898=== CONT TestCacheConfigHandler/no_cache_url_configured1899--- PASS: TestCacheConfigHandler (0.00s)1900 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)1901 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)1902 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)1903 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)1904=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info19052026/09/16 10:26:12 INFO Received uploads request method=POST path=/1906=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key19072026/09/16 10:26:12 INFO Received complete multipart upload request method=POST path=/1908=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key19092026/09/16 10:26:12 INFO Received request for more parts method=POST path=/1910=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal19112026/09/16 10:26:12 INFO Received uploads request method=POST path=/1912--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)1913 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1914 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1915 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1916 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1917=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure19182026/09/16 10:26:12 INFO Received uploads request method=POST path=/1919--- PASS: TestResolveDBConnectionString (0.00s)1920 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)1921 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)1922 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)1923 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)1924 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)19252026/09/16 10:26:12 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"19262026/09/16 10:26:12 INFO Received uploads request method=POST path=/api/pending_closures19272026/09/16 10:26:12 INFO Received uploads request method=POST path=/api/pending_closures19282026/09/16 10:26:12 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)19292026/09/16 10:26:12 INFO Uploading 3dbsk96r5q7wbjda2vzkgys7ww5j5mqq-ca-test (144B)19302026/09/16 10:26:12 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"19312026/09/16 10:26:12 WARN Failed to register uploaded object key=log/dildsfcmlwrzrc61pxwcv3sslhgx2g6i-ca-test.drv error="server returned 404: 404 page not found\n"19322026/09/16 10:26:12 WARN Failed to register uploaded object key=3dbsk96r5q7wbjda2vzkgys7ww5j5mqq.ls error="server returned 404: 404 page not found\n"19332026/09/16 10:26:12 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign19342026/09/16 10:26:12 INFO Signed narinfos id=1 count=119352026/09/16 10:26:12 INFO Uploading 1 narinfos19362026/09/16 10:26:12 WARN Failed to register uploaded object key=3dbsk96r5q7wbjda2vzkgys7ww5j5mqq.narinfo error="server returned 404: 404 page not found\n"19372026/09/16 10:26:12 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete19382026/09/16 10:26:12 INFO Completed upload id=119392026/09/16 10:26:12 INFO Upload complete. (134ms)1940=== NAME TestClientCADerivations1941 client_ca_test.go:180: Narinfo contains CA field: StorePath: /nix/var/nix/builds/nix-36727-1823504073/TestClientCADerivations1134325837/001/store/3dbsk96r5q7wbjda2vzkgys7ww5j5mqq-ca-test1942 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1943 Compression: zstd1944 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1945 NarSize: 1441946 References: 1947 Deriver: /nix/var/nix/builds/nix-36727-1823504073/TestClientCADerivations1134325837/001/store/dildsfcmlwrzrc61pxwcv3sslhgx2g6i-ca-test.drv1948 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1949 client_ca_test.go:185: Checking for realisation files in S3...1950 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1951 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache1952 client_ca_test.go:258: nix copy output: error: binary cache 's3://bucket52?endpoint=http://localhost:55340®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/nix/var/nix/builds/nix-36727-1823504073/TestClientCADerivations1134325837/001/store'1953 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 11954=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts19552026/09/16 10:26:12 INFO Received request for more parts method=POST path=/1956--- PASS: TestClientCADerivations (2.11s)1957=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart19582026/09/16 10:26:12 INFO Received complete multipart upload request method=POST path=/1959=== CONT TestService_RequireScope_OIDC/builder_may_write19602026/09/16 10:26:12 INFO OIDC auth successful provider=test scopes=[write]1961=== CONT TestService_RequireScope_OIDC/static_token_may_admin1962=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read1963=== CONT TestService_RequireScope_OIDC/writer_implies_read19642026/09/16 10:26:12 INFO OIDC auth successful provider=test scopes=[write]1965=== CONT TestService_RequireScope_OIDC/reader_may_read19662026/09/16 10:26:12 INFO OIDC auth successful provider=test scopes=[read]1967=== CONT TestService_RequireScope_OIDC/static_token_may_write1968=== CONT TestService_RequireScope_OIDC/ops_may_not_write19692026/09/16 10:26:12 INFO OIDC auth successful provider=test scopes=[admin]1970=== CONT TestService_RequireScope_OIDC/reader_may_not_write19712026/09/16 10:26:12 INFO OIDC auth successful provider=test scopes=[read]1972=== CONT TestService_RequireScope_OIDC/ops_may_admin19732026/09/16 10:26:12 INFO OIDC auth successful provider=test scopes=[admin]1974=== CONT TestService_RequireScope_OIDC/builder_may_not_admin19752026/09/16 10:26:12 INFO OIDC auth successful provider=test scopes=[write]1976=== CONT TestIsValidCachePath/narinfo1977=== CONT TestIsValidCachePath/random_path1978=== CONT TestIsValidCachePath/invalid_char_u1979=== CONT TestIsValidCachePath/invalid_char_e1980=== CONT TestIsValidCachePath/traversal_in_middle1981=== CONT TestIsValidCachePath/traversal_parent1982=== CONT TestIsValidCachePath/index.html1983=== CONT TestIsValidCachePath/nix-cache-info1984=== CONT TestIsValidCachePath/realisation1985=== CONT TestIsValidCachePath/log1986=== CONT TestIsValidCachePath/ls1987=== CONT TestIsValidCachePath/nar_uncompressed1988=== CONT TestIsValidCachePath/nar_bz21989=== CONT TestIsValidCachePath/nar_xz1990=== CONT TestIsValidCachePath/nar_zst1991=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1992=== CONT TestIsValidCachePath/short_hash1993=== CONT TestIsValidCachePath/empty1994=== CONT TestIsValidCachePath/wrong_extension1995=== CONT TestIsValidCachePath/leading_slash1996--- PASS: TestIsValidCachePath (0.00s)1997 --- PASS: TestIsValidCachePath/narinfo (0.00s)1998 --- PASS: TestIsValidCachePath/random_path (0.00s)1999 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)2000 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)2001 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)2002 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)2003 --- PASS: TestIsValidCachePath/index.html (0.00s)2004 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)2005 --- PASS: TestIsValidCachePath/realisation (0.00s)2006 --- PASS: TestIsValidCachePath/log (0.00s)2007 --- PASS: TestIsValidCachePath/ls (0.00s)2008 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)2009 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)2010 --- PASS: TestIsValidCachePath/nar_xz (0.00s)2011 --- PASS: TestIsValidCachePath/nar_zst (0.00s)2012 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)2013 --- PASS: TestIsValidCachePath/short_hash (0.00s)2014 --- PASS: TestIsValidCachePath/empty (0.00s)2015 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)2016 --- PASS: TestIsValidCachePath/leading_slash (0.00s)2017=== CONT TestParseSingleRange/none2018=== CONT TestParseSingleRange/open-ended2019=== CONT TestParseSingleRange/start_far_past_EOF2020=== CONT TestParseSingleRange/start_past_EOF2021=== CONT TestParseSingleRange/single_byte2022=== CONT TestParseSingleRange/suffix_exceeds_size2023=== CONT TestParseSingleRange/suffix2024=== CONT TestParseSingleRange/end_clamped_to_size2025=== CONT TestParseSingleRange/malformed_both_empty2026=== CONT TestParseSingleRange/closed2027=== CONT TestParseSingleRange/malformed_end_before_start2028=== CONT TestParseSingleRange/multi-range_ignored2029=== CONT TestParseSingleRange/malformed_no_dash2030=== CONT TestParseSingleRange/unknown_unit2031--- PASS: TestParseSingleRange (0.00s)2032 --- PASS: TestParseSingleRange/none (0.00s)2033 --- PASS: TestParseSingleRange/open-ended (0.00s)2034 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)2035 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)2036 --- PASS: TestParseSingleRange/single_byte (0.00s)2037 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)2038 --- PASS: TestParseSingleRange/suffix (0.00s)2039 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)2040 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)2041 --- PASS: TestParseSingleRange/closed (0.00s)2042 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)2043 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)2044 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)2045 --- PASS: TestParseSingleRange/unknown_unit (0.00s)2046=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token20472026/09/16 10:26:12 INFO OIDC auth successful provider=test scopes=[write]2048=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected20492026/09/16 10:26:12 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]2050=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2051=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected20522026/09/16 10:26:12 WARN Authentication failed token_preview=eyJhbGciOi...lZf5Tonhiw token_length=702 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]2053=== CONT TestIsValidUploadKey/narinfo2054=== CONT TestIsValidUploadKey/realisation_plus_in_output2055=== CONT TestIsValidUploadKey/unknown_type2056=== CONT TestIsValidUploadKey/empty_key2057=== CONT TestIsValidUploadKey/absolute2058=== CONT TestIsValidUploadKey/traversal_nar2059=== CONT TestIsValidUploadKey/traversal2060=== CONT TestIsValidUploadKey/listing_key,_narinfo_type2061=== CONT TestIsValidUploadKey/nar_key,_narinfo_type2062=== CONT TestIsValidUploadKey/narinfo_key,_nar_type2063=== CONT TestIsValidUploadKey/index.html2064=== CONT TestIsValidUploadKey/nix-cache-info2065=== CONT TestIsValidUploadKey/build_log_home-manager_file2066=== CONT TestIsValidUploadKey/realisation2067=== CONT TestIsValidUploadKey/build_log_equals2068=== CONT TestIsValidUploadKey/build_log_question_mark2069=== CONT TestIsValidUploadKey/build_log_plus_in_name2070=== CONT TestIsValidUploadKey/nar_plain2071=== CONT TestIsValidUploadKey/build_log2072=== CONT TestIsValidUploadKey/listing2073=== CONT TestIsValidUploadKey/nar_xz2074=== CONT TestIsValidUploadKey/nar_zst2075--- PASS: TestIsValidUploadKey (0.00s)2076 --- PASS: TestIsValidUploadKey/narinfo (0.00s)2077 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)2078 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)2079 --- PASS: TestIsValidUploadKey/empty_key (0.00s)2080 --- PASS: TestIsValidUploadKey/absolute (0.00s)2081 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)2082 --- PASS: TestIsValidUploadKey/traversal (0.00s)2083 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)2084 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)2085 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)2086 --- PASS: TestIsValidUploadKey/index.html (0.00s)2087 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)2088 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)2089 --- PASS: TestIsValidUploadKey/realisation (0.00s)2090 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)2091 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)2092 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)2093 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)2094 --- PASS: TestIsValidUploadKey/build_log (0.00s)2095 --- PASS: TestIsValidUploadKey/listing (0.00s)2096 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)2097 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)2098=== CONT TestProxyWriteTimeout/narinfo2099=== CONT TestProxyWriteTimeout/10_GiB_nar2100=== CONT TestProxyWriteTimeout/unknown_size2101=== CONT TestProxyWriteTimeout/1_GiB_nar2102--- PASS: TestProxyWriteTimeout (0.00s)2103 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)2104 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)2105 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)2106 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)2107=== CONT TestClientErrorHandling/InvalidStorePath2108--- PASS: TestUploadHandlersRejectOversizedBody (0.03s)2109 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.27s)2110 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.02s)2111 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.02s)2112=== CONT TestClientErrorHandling/ServerNotAvailable2113--- PASS: TestService_AuthMiddleware_OIDC (2.09s)2114 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)2115 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)2116 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)2117 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)2118--- PASS: TestService_RequireScope_OIDC (2.23s)2119 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)2120 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)2121 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)2122 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)2123 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)2124 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)2125 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)2126 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)2127 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)2128 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)21292026-09-16 10:26:12.916 UTC [37192] ERROR: relation "goose_db_version" does not exist at character 3621302026-09-16 10:26:12.916 UTC [37192] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC21312026/09/16 10:26:13 OK 20241026095416_initial_model.sql (64.89ms)21322026/09/16 10:26:13 OK 20251210153512_drop_unused_gin_index.sql (7.79ms)21332026/09/16 10:26:13 OK 20251218171726_add_pins.sql (9.83ms)21342026/09/16 10:26:13 OK 20260628120000_add_object_size_and_stats.sql (30.3ms)21352026/09/16 10:26:13 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-config21362026/09/16 10:26:13 OK 20260905000000_add_claims.sql (17.14ms)21372026/09/16 10:26:13 goose: successfully migrated database to version: 2026090500000021382026/09/16 10:26:13 OK 1_commit_pending_closure.sql (1.54ms)21392026/09/16 10:26:13 OK 2_object_stats_trigger.sql (229.42µs)21402026/09/16 10:26:13 goose: up to current file version: 221412026/09/16 10:26:13 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=208.249749ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2142--- PASS: TestObjectStatsTrigger (1.64s)2143=== CONT TestClientErrorHandling/InvalidAuthToken2144=== NAME TestOrphanedObjectsGC2145 orphaned_objects_gc_test.go:290: GC Test Summary:2146 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A2147 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B2148 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)2149 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)2150 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects2151--- PASS: TestOrphanedObjectsGC (1.83s)2152--- PASS: TestService_ReadScope_PublicByDefault (1.60s)21532026/09/16 10:26:13 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=360.491191ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21542026/09/16 10:26:13 INFO Received complete multipart upload request method=POST path=/api/multipart/complete21552026/09/16 10:26:13 INFO Completed multipart upload object_key=nar/0000000000000000000000000000001700000000000000000000.nar.zst upload_id=MGI0NDE3ZTYtYjdlMy00NTZmLTkxYTctYjE3NGY3YzNjMzEzLjJmNjRmODAzLTM0ZmItNDQ3Ni1hYzMwLWViZTc1YWQwMTIzOXgxNzg5NTU0MzcyNjUwNjM2MDAw parts=1021562026/09/16 10:26:13 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete21572026/09/16 10:26:13 INFO Completed upload id=121582026/09/16 10:26:13 WARN claim: cannot clear write deadline error="feature not supported"21592026/09/16 10:26:13 INFO Aborted multipart uploads count=021602026/09/16 10:26:13 WARN Force mode enabled - objects will be deleted immediately without grace period2161--- PASS: TestClaim_StreamsThroughServer (3.00s)21622026/09/16 10:26: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=021632026-09-16 10:26:13.577 UTC [37202] ERROR: relation "goose_db_version" does not exist at character 3621642026-09-16 10:26:13.577 UTC [37202] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC21652026/09/16 10:26:13 INFO Vacuumed table table=pending_closures21662026/09/16 10:26:13 INFO Vacuumed table table=pending_objects21672026/09/16 10:26:13 INFO Vacuumed table table=multipart_uploads21682026/09/16 10:26:13 INFO Vacuumed table table=closures21692026/09/16 10:26:13 INFO Vacuumed table table=objects2170--- PASS: TestClaim_InputsTouched (2.34s)21712026/09/16 10:26:13 OK 20241026095416_initial_model.sql (7.23ms)21722026/09/16 10:26:13 OK 20251210153512_drop_unused_gin_index.sql (2.27ms)21732026/09/16 10:26:13 OK 20251218171726_add_pins.sql (1.2ms)21742026/09/16 10:26:13 OK 20260628120000_add_object_size_and_stats.sql (2.53ms)21752026/09/16 10:26:13 OK 20260905000000_add_claims.sql (1.49ms)21762026/09/16 10:26:13 goose: successfully migrated database to version: 2026090500000021772026/09/16 10:26:13 OK 1_commit_pending_closure.sql (1.34ms)21782026/09/16 10:26:13 OK 2_object_stats_trigger.sql (325.88µs)21792026/09/16 10:26:13 goose: up to current file version: 221802026/09/16 10:26:13 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=761.376289ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21812026-09-16 10:26:13.788 UTC [37208] ERROR: relation "goose_db_version" does not exist at character 3621822026-09-16 10:26:13.788 UTC [37208] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC21832026/09/16 10:26:13 OK 20241026095416_initial_model.sql (3.32ms)21842026/09/16 10:26:13 OK 20251210153512_drop_unused_gin_index.sql (440.71µs)21852026/09/16 10:26:13 OK 20251218171726_add_pins.sql (837.63µs)21862026/09/16 10:26:13 OK 20260628120000_add_object_size_and_stats.sql (926.17µs)21872026/09/16 10:26:13 OK 20260905000000_add_claims.sql (1.02ms)21882026/09/16 10:26:13 goose: successfully migrated database to version: 2026090500000021892026/09/16 10:26:13 OK 1_commit_pending_closure.sql (888.13µs)21902026/09/16 10:26:13 OK 2_object_stats_trigger.sql (245.38µs)21912026/09/16 10:26:13 goose: up to current file version: 22192=== NAME TestClientWithDependencies2193 client_integration_test.go:594: Built derivation: /nix/var/nix/builds/nix-36727-1823504073/TestClientWithDependencies3941261440/001/store/p423w9s7bjyjqkavp4gy7yvm4mkrw7vx-test-script2194 client_integration_test.go:596: Found 1 dependencies (including self)21952026/09/16 10:26:13 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"21962026/09/16 10:26:13 INFO Received uploads request method=POST path=/api/pending_closures21972026/09/16 10:26:13 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)21982026/09/16 10:26:13 INFO Uploading p423w9s7bjyjqkavp4gy7yvm4mkrw7vx-test-script (136B)21992026/09/16 10:26:13 WARN Failed to register uploaded object key=log/pdbxzhjzryhdh514w5y8nwb640y73chh-test-script.drv error="server returned 404: 404 page not found\n"22002026/09/16 10:26:13 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"22012026/09/16 10:26:13 WARN Failed to register uploaded object key=p423w9s7bjyjqkavp4gy7yvm4mkrw7vx.ls error="server returned 404: 404 page not found\n"22022026/09/16 10:26:13 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign22032026/09/16 10:26:13 INFO Signed narinfos id=1 count=122042026/09/16 10:26:13 INFO Uploading 1 narinfos22052026/09/16 10:26:13 WARN Failed to register uploaded object key=p423w9s7bjyjqkavp4gy7yvm4mkrw7vx.narinfo error="server returned 404: 404 page not found\n"22062026/09/16 10:26:13 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete22072026/09/16 10:26:13 INFO Completed upload id=122082026/09/16 10:26:13 INFO Upload complete. (39ms)2209 client_integration_test.go:598: Skipping nix copy test - isolated store (/nix/var/nix/builds/nix-36727-1823504073/TestClientWithDependencies3941261440/001/store) requires matching store prefix2210--- PASS: TestClientWithDependencies (1.52s)22112026/09/16 10:26:14 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"2212=== NAME TestOrphanedObjectsGCStressTest2213 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains2214 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion22152026/09/16 10:26:14 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"2216 orphaned_objects_gc_test.go:509: Stress test completed successfully:2217 orphaned_objects_gc_test.go:510: - Active objects preserved: 202218 orphaned_objects_gc_test.go:511: - Objects deleted: 2102219 orphaned_objects_gc_test.go:512: - Total GC'd: 2102220--- PASS: TestOrphanedObjectsGCStressTest (2.68s)22212026/09/16 10:26:14 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=02222=== NAME TestClientIntegration2223 client_integration_test.go:304: Objects in database after GC:2224 client_integration_test.go:304: Successfully deleted all objects with GC --force2225--- PASS: TestClientIntegration (4.04s)22262026/09/16 10:26:14 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.631847779s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22272026/09/16 10:26:16 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: sending request: request failed after retries: Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused"22282026/09/16 10:26:16 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22292026/09/16 10:26:16 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=198.555441ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22302026/09/16 10:26:16 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=409.826826ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22312026/09/16 10:26:16 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=857.799169ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22322026/09/16 10:26:17 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.683181474s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2233--- PASS: TestClientErrorHandling (0.00s)2234 --- PASS: TestClientErrorHandling/InvalidStorePath (0.94s)2235 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.86s)2236 --- PASS: TestClientErrorHandling/ServerNotAvailable (6.64s)2237PASS2238{"timestamp":"2026-09-16T10:26:19.504421Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:55509","error_kind":"io_error","error":"Cancelled","result":"transport_error","target":"rustfs::server::http","filename":"rustfs/src/server/http.rs","line_number":1880,"threadName":"rustfs-worker","threadId":"ThreadId(6)"}22392026-09-16 10:26:19.607 UTC [36826] LOG: received smart shutdown request22402026-09-16 10:26:19.608 UTC [36826] LOG: background worker "logical replication launcher" (PID 36836) exited with exit code 122412026-09-16 10:26:19.610 UTC [36831] LOG: shutting down22422026-09-16 10:26:19.610 UTC [36831] LOG: checkpoint starting: shutdown immediate22432026-09-16 10:26:20.624 UTC [36831] LOG: checkpoint complete: wrote 13471 buffers (82.2%), wrote 3 SLRU buffers; 0 WAL file(s) added, 0 removed, 18 recycled; write=0.660 s, sync=0.351 s, total=1.014 s; sync files=21000, longest=0.001 s, average=0.001 s; distance=287765 kB, estimate=287765 kB; lsn=0/130923D0, redo lsn=0/130923D022442026-09-16 10:26:20.629 UTC [36826] LOG: database system is shut down2245Running OIDC tests...2246=== RUN TestGlobMatch2247=== PAUSE TestGlobMatch2248=== RUN TestAudienceForIssuer2249=== PAUSE TestAudienceForIssuer2250=== RUN TestValidateToken_ValidToken2251=== PAUSE TestValidateToken_ValidToken2252=== RUN TestValidateToken_WrongAudience2253=== PAUSE TestValidateToken_WrongAudience2254=== RUN TestValidateToken_Expired2255=== PAUSE TestValidateToken_Expired2256=== RUN TestValidateToken_BoundClaimsMismatch2257=== PAUSE TestValidateToken_BoundClaimsMismatch2258=== RUN TestValidateToken_BoundSubjectMismatch2259=== PAUSE TestValidateToken_BoundSubjectMismatch2260=== RUN TestValidateToken_MultipleProviders2261=== PAUSE TestValidateToken_MultipleProviders2262=== RUN TestValidateToken_NoMatchingProvider2263=== PAUSE TestValidateToken_NoMatchingProvider2264=== RUN TestValidateToken_KubernetesServiceAccount2265=== PAUSE TestValidateToken_KubernetesServiceAccount2266=== RUN TestNewValidator_KubernetesRequiresCA2267=== PAUSE TestNewValidator_KubernetesRequiresCA2268=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2269=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2270=== RUN TestScopes_LegacyProviderDefaultsToWrite2271=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2272=== RUN TestScopes_Rules2273=== PAUSE TestScopes_Rules2274=== RUN TestScopes_ConfigValidation2275=== PAUSE TestScopes_ConfigValidation2276=== CONT TestGlobMatch2277=== RUN TestGlobMatch/foo_foo2278=== PAUSE TestGlobMatch/foo_foo2279=== CONT TestValidateToken_NoMatchingProvider2280=== CONT TestScopes_LegacyProviderDefaultsToWrite2281=== RUN TestGlobMatch/foo_bar2282=== PAUSE TestGlobMatch/foo_bar2283=== RUN TestGlobMatch/*_2284=== PAUSE TestGlobMatch/*_2285=== RUN TestGlobMatch/*_anything2286=== PAUSE TestGlobMatch/*_anything2287=== RUN TestGlobMatch/foo*_foo2288=== PAUSE TestGlobMatch/foo*_foo2289=== RUN TestGlobMatch/foo*_foobar2290=== PAUSE TestGlobMatch/foo*_foobar2291=== RUN TestGlobMatch/foo*_bar2292=== CONT TestValidateToken_MultipleProviders2293=== CONT TestValidateToken_BoundSubjectMismatch2294=== CONT TestValidateToken_BoundClaimsMismatch2295=== CONT TestValidateToken_Expired2296=== CONT TestValidateToken_WrongAudience2297=== CONT TestValidateToken_ValidToken2298=== CONT TestAudienceForIssuer2299--- PASS: TestAudienceForIssuer (0.00s)2300=== CONT TestScopes_ConfigValidation2301=== PAUSE TestGlobMatch/foo*_bar2302=== RUN TestGlobMatch/*bar_bar2303=== PAUSE TestGlobMatch/*bar_bar2304=== RUN TestGlobMatch/*bar_foobar2305=== PAUSE TestGlobMatch/*bar_foobar2306=== RUN TestGlobMatch/*bar_foo2307=== PAUSE TestGlobMatch/*bar_foo2308=== RUN TestGlobMatch/foo*bar_foobar2309=== PAUSE TestGlobMatch/foo*bar_foobar2310=== RUN TestGlobMatch/foo*bar_foo123bar2311=== PAUSE TestGlobMatch/foo*bar_foo123bar2312=== RUN TestGlobMatch/foo*bar_foobarbaz2313=== PAUSE TestGlobMatch/foo*bar_foobarbaz2314=== RUN TestGlobMatch/*/*_foo/bar2315=== PAUSE TestGlobMatch/*/*_foo/bar2316=== RUN TestGlobMatch/*/*_foo2317=== PAUSE TestGlobMatch/*/*_foo2318=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2319=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2320=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02321=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02322=== RUN TestGlobMatch/refs/*/main_refs/heads/main2323=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2324=== RUN TestGlobMatch/fo?_foo2325=== PAUSE TestGlobMatch/fo?_foo2326=== RUN TestGlobMatch/fo?_fo2327=== PAUSE TestGlobMatch/fo?_fo2328=== RUN TestGlobMatch/fo?_fooo2329=== PAUSE TestGlobMatch/fo?_fooo2330=== RUN TestGlobMatch/?oo_foo2331=== PAUSE TestGlobMatch/?oo_foo2332=== RUN TestGlobMatch/?oo_boo2333=== PAUSE TestGlobMatch/?oo_boo2334=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2335=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2336=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2337=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2338=== CONT TestNewValidator_KubernetesRequiresCA23392026/09/16 10:26:21 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:55647/oidc23402026/09/16 10:26:21 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:55648/oidc23412026/09/16 10:26:21 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:55645/oidc23422026/09/16 10:26:21 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:55643/oidc2343--- PASS: TestScopes_ConfigValidation (0.00s)2344=== CONT TestValidateToken_KubernetesIssuerFromOwnToken23452026/09/16 10:26:21 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:55642/oidc23462026/09/16 10:26:21 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:55646/oidc23472026/09/16 10:26:21 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:55644/oidc23482026/09/16 10:26:21 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:55641/oidc2349--- PASS: TestValidateToken_ValidToken (0.01s)2350=== CONT TestValidateToken_KubernetesServiceAccount2351--- PASS: TestValidateToken_WrongAudience (0.01s)2352=== CONT TestScopes_Rules2353--- PASS: TestValidateToken_NoMatchingProvider (0.01s)2354--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.01s)2355=== CONT TestGlobMatch/foo_foo2356=== CONT TestGlobMatch/*/*_foo/bar2357=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2358=== CONT TestGlobMatch/?oo_boo2359=== CONT TestGlobMatch/?oo_foo2360=== CONT TestGlobMatch/fo?_fooo2361=== CONT TestGlobMatch/fo?_fo2362=== CONT TestGlobMatch/fo?_foo2363=== CONT TestGlobMatch/refs/*/main_refs/heads/main2364=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02365=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2366=== CONT TestGlobMatch/*/*_foo2367=== CONT TestGlobMatch/*bar_bar2368=== CONT TestGlobMatch/foo*bar_foobarbaz2369=== CONT TestGlobMatch/foo*bar_foo123bar2370=== CONT TestGlobMatch/foo*bar_foobar2371=== CONT TestGlobMatch/*bar_foo2372=== CONT TestGlobMatch/*bar_foobar2373=== CONT TestGlobMatch/foo*_foo2374=== CONT TestGlobMatch/foo*_bar2375=== CONT TestGlobMatch/foo*_foobar2376=== CONT TestGlobMatch/*_2377=== CONT TestGlobMatch/*_anything2378=== CONT TestGlobMatch/foo_bar23792026/09/16 10:26:21 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:55649/oidc23802026/09/16 10:26:21 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC1232381=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2382--- PASS: TestGlobMatch (0.00s)2383 --- PASS: TestGlobMatch/foo_foo (0.00s)2384 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2385 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2386 --- PASS: TestGlobMatch/?oo_boo (0.00s)2387 --- PASS: TestGlobMatch/?oo_foo (0.00s)2388 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2389 --- PASS: TestGlobMatch/fo?_fo (0.00s)2390 --- PASS: TestGlobMatch/fo?_foo (0.00s)2391 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2392 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2393 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2394 --- PASS: TestGlobMatch/*/*_foo (0.00s)2395 --- PASS: TestGlobMatch/*bar_bar (0.00s)2396 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2397 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2398 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2399 --- PASS: TestGlobMatch/*bar_foo (0.00s)2400 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2401 --- PASS: TestGlobMatch/foo*_foo (0.00s)2402 --- PASS: TestGlobMatch/foo*_bar (0.00s)2403 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2404 --- PASS: TestGlobMatch/*_ (0.00s)2405 --- PASS: TestGlobMatch/*_anything (0.00s)2406 --- PASS: TestGlobMatch/foo_bar (0.00s)2407 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2408--- PASS: TestValidateToken_Expired (0.01s)2409--- PASS: TestValidateToken_BoundClaimsMismatch (0.01s)24102026/09/16 10:26:21 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:55664/oidc2411--- PASS: TestValidateToken_BoundSubjectMismatch (0.01s)2412--- PASS: TestValidateToken_MultipleProviders (0.01s)24132026/09/16 10:26:21 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:556632414--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.01s)24152026/09/16 10:26:21 http: TLS handshake error from 127.0.0.1:55660: remote error: tls: bad certificate2416--- PASS: TestNewValidator_KubernetesRequiresCA (0.02s)2417--- PASS: TestValidateToken_KubernetesServiceAccount (0.01s)2418--- PASS: TestScopes_Rules (0.01s)2419PASS2420Running hook tests...2421=== RUN TestSendPathsEmpty2422=== PAUSE TestSendPathsEmpty2423=== RUN TestQueueEnqueueAndFetch2424=== PAUSE TestQueueEnqueueAndFetch2425=== RUN TestQueueDeduplication2426=== PAUSE TestQueueDeduplication2427=== RUN TestQueueRemove2428=== PAUSE TestQueueRemove2429=== RUN TestQueueFetchBatchLimit2430=== PAUSE TestQueueFetchBatchLimit2431=== RUN TestQueueRetryMovesToBack2432=== PAUSE TestQueueRetryMovesToBack2433=== RUN TestQueueFetchRemoveLifecycle2434=== PAUSE TestQueueFetchRemoveLifecycle2435=== RUN TestQueueConcurrentWriters2436=== PAUSE TestQueueConcurrentWriters2437=== RUN TestQueueRemoveLargeClosure2438=== PAUSE TestQueueRemoveLargeClosure2439=== RUN TestServerClientIntegration2440=== PAUSE TestServerClientIntegration2441=== RUN TestServerQueueError2442=== PAUSE TestServerQueueError2443=== RUN TestGetListenerSocketActivation2444 server_test.go:210: === RUN TestGetListenerSocketActivation2445 --- PASS: TestGetListenerSocketActivation (0.00s)2446 PASS2447 2448--- PASS: TestGetListenerSocketActivation (0.01s)2449=== RUN TestDrainIsolatesPoisonPath2450=== PAUSE TestDrainIsolatesPoisonPath2451=== RUN TestRunNotBlockedByPoisonHead2452=== PAUSE TestRunNotBlockedByPoisonHead2453=== RUN TestDrainGivesUpWhenServerDown2454=== PAUSE TestDrainGivesUpWhenServerDown2455=== RUN TestFailedPathPrunedByLaterClosure2456=== PAUSE TestFailedPathPrunedByLaterClosure2457=== RUN TestWorkerUploadsAndRemoves2458=== PAUSE TestWorkerUploadsAndRemoves2459=== RUN TestWorkerSkipsGCdPaths2460=== PAUSE TestWorkerSkipsGCdPaths2461=== RUN TestWorkerPrunesClosureDeps2462=== PAUSE TestWorkerPrunesClosureDeps2463=== RUN TestDrainTimeout2464=== PAUSE TestDrainTimeout2465=== CONT TestSendPathsEmpty2466=== CONT TestWorkerPrunesClosureDeps2467=== CONT TestWorkerUploadsAndRemoves2468--- PASS: TestSendPathsEmpty (0.00s)2469=== CONT TestWorkerSkipsGCdPaths2470=== CONT TestFailedPathPrunedByLaterClosure2471=== CONT TestQueueConcurrentWriters2472=== CONT TestDrainGivesUpWhenServerDown2473=== CONT TestRunNotBlockedByPoisonHead2474=== CONT TestQueueFetchRemoveLifecycle2475=== CONT TestDrainIsolatesPoisonPath2476=== CONT TestQueueRetryMovesToBack24772026/09/16 10:26:21 INFO Uploading batch count=124782026/09/16 10:26:21 ERROR Upload failed error="upload failed" count=124792026/09/16 10:26:21 INFO Uploading batch count=424802026/09/16 10:26:21 ERROR Upload failed error="upload failed" count=424812026/09/16 10:26:21 INFO Upload queue status pending=324822026/09/16 10:26:21 INFO Upload queue status pending=224832026/09/16 10:26:21 INFO Uploading batch count=124842026/09/16 10:26:21 ERROR Upload failed error="upload failed" count=124852026/09/16 10:26:21 INFO Uploading batch count=124862026/09/16 10:26:21 INFO Uploading batch count=124872026/09/16 10:26:21 INFO Uploading batch count=224882026/09/16 10:26:21 ERROR Upload failed error="upload failed" count=224892026/09/16 10:26:21 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-36727-1823504073/TestDrainGivesUpWhenServerDown2420273731/002/a2490--- PASS: TestQueueFetchRemoveLifecycle (0.01s)2491=== CONT TestServerQueueError24922026/09/16 10:26:21 INFO Upload queue status pending=224932026/09/16 10:26:21 INFO Uploading batch count=224942026/09/16 10:26:21 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-36727-1823504073/TestDrainIsolatesPoisonPath3536858976/002/bbb24952026/09/16 10:26:21 INFO Uploading batch count=124962026/09/16 10:26:21 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-36727-1823504073/TestDrainGivesUpWhenServerDown2420273731/002/b24972026/09/16 10:26:21 INFO Upload queue status pending=224982026/09/16 10:26:21 WARN Store path no longer exists (garbage collected?), removing from queue path=/nix/var/nix/builds/nix-36727-1823504073/TestWorkerSkipsGCdPaths3995283247/002/nonexistent24992026/09/16 10:26:21 INFO Uploading batch count=225002026/09/16 10:26:21 ERROR Upload failed error="upload failed" count=225012026/09/16 10:26:21 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-36727-1823504073/TestDrainGivesUpWhenServerDown2420273731/002/c2502--- PASS: TestQueueRetryMovesToBack (0.01s)2503=== CONT TestQueueFetchBatchLimit25042026/09/16 10:26:21 ERROR Failed to queue paths error="permission denied" count=125052026/09/16 10:26:21 INFO Uploading batch count=125062026/09/16 10:26:21 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-36727-1823504073/TestDrainGivesUpWhenServerDown2420273731/002/d2507--- PASS: TestServerQueueError (0.00s)25082026/09/16 10:26:21 INFO Uploading batch count=12509=== CONT TestServerClientIntegration25102026/09/16 10:26:21 ERROR Upload failed error="upload failed" count=125112026/09/16 10:26:21 INFO Uploading batch count=225122026/09/16 10:26:21 ERROR Upload failed error="upload failed" count=225132026/09/16 10:26:21 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-36727-1823504073/TestDrainGivesUpWhenServerDown2420273731/002/e25142026/09/16 10:26:21 INFO Uploading batch count=125152026/09/16 10:26:21 ERROR Upload failed error="upload failed" count=125162026/09/16 10:26:21 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-36727-1823504073/TestDrainGivesUpWhenServerDown2420273731/002/f25172026/09/16 10:26:21 INFO Uploading batch count=125182026/09/16 10:26:21 ERROR Upload failed error="upload failed" count=125192026/09/16 10:26:21 ERROR Drain finished with paths left in queue remaining=102520--- PASS: TestFailedPathPrunedByLaterClosure (0.02s)2521=== CONT TestQueueRemove25222026/09/16 10:26:21 ERROR Drain finished with paths left in queue remaining=12523--- PASS: TestServerClientIntegration (0.00s)2524=== CONT TestQueueDeduplication2525--- PASS: TestDrainIsolatesPoisonPath (0.02s)2526=== CONT TestQueueEnqueueAndFetch2527--- PASS: TestQueueFetchBatchLimit (0.00s)2528=== CONT TestDrainTimeout2529--- PASS: TestDrainGivesUpWhenServerDown (0.02s)2530=== CONT TestQueueRemoveLargeClosure2531--- PASS: TestQueueDeduplication (0.00s)2532--- PASS: TestQueueRemove (0.01s)2533--- PASS: TestQueueEnqueueAndFetch (0.00s)25342026/09/16 10:26:21 INFO Uploading batch count=22535--- PASS: TestWorkerPrunesClosureDeps (0.03s)2536--- PASS: TestWorkerUploadsAndRemoves (0.03s)2537--- PASS: TestWorkerSkipsGCdPaths (0.03s)2538--- PASS: TestQueueRemoveLargeClosure (0.05s)2539--- PASS: TestQueueConcurrentWriters (0.15s)25402026/09/16 10:26:22 ERROR Upload failed error="context deadline exceeded" count=225412026/09/16 10:26:22 ERROR Drain finished with paths left in queue remaining=42542--- PASS: TestDrainTimeout (0.21s)25432026/09/16 10:26:22 INFO Uploading batch count=125442026/09/16 10:26:22 INFO Uploading batch count=125452026/09/16 10:26:22 INFO Uploading batch count=125462026/09/16 10:26:22 ERROR Upload failed error="upload failed" count=125472026/09/16 10:26:22 INFO Uploading batch count=125482026/09/16 10:26:22 ERROR Upload failed error="upload failed" count=125492026/09/16 10:26:22 INFO Uploading batch count=125502026/09/16 10:26:22 ERROR Upload failed error="upload failed" count=125512026/09/16 10:26:22 INFO Uploading batch count=125522026/09/16 10:26:22 ERROR Upload failed error="upload failed" count=125532026/09/16 10:26:22 ERROR Drain finished with paths left in queue remaining=12554--- PASS: TestRunNotBlockedByPoisonHead (1.04s)2555PASS