niks3-go-unit-tests
checks.aarch64-darwin.go-unit-tests
· build #213
· 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.27s)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 TestStaticToken89--- PASS: TestShellSplit (0.00s)90=== CONT TestFileTokenMissing91--- PASS: TestStaticToken (0.00s)92=== CONT TestFileTokenReadsAndCaches93=== CONT TestScriptTokenEmptyCommand94--- PASS: TestScriptTokenEmptyCommand (0.00s)95=== CONT TestConvertHashToNix3296=== RUN TestConvertHashToNix32/SRI_format_to_Nix3297=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix3298=== RUN TestConvertHashToNix32/already_Nix32_format99=== PAUSE TestConvertHashToNix32/already_Nix32_format100=== RUN TestConvertHashToNix32/invalid_format101=== PAUSE TestConvertHashToNix32/invalid_format102=== CONT TestScriptTokenScriptFails103=== CONT TestDoWithRetry_BodyReplayedViaGetBody104=== CONT TestScriptTokenBadJSON105=== CONT TestScriptTokenEmptyToken106=== CONT TestScriptTokenCachesUntilRefresh107=== CONT TestScriptTokenNoExpiryRerunsEveryCall108=== CONT TestFileTokenEmpty109--- PASS: TestFileTokenReadsAndCaches (0.00s)110=== CONT TestResolveStorePath111--- PASS: TestFileTokenMissing (0.00s)112=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess113--- PASS: TestResolveStorePath (0.00s)114=== CONT TestRateLimiterFeedback115=== RUN TestRateLimiterFeedback/429_enables_limiter116=== PAUSE TestRateLimiterFeedback/429_enables_limiter117=== RUN TestRateLimiterFeedback/503_enables_limiter118=== PAUSE TestRateLimiterFeedback/503_enables_limiter119=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter120=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter121=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter122=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter123=== CONT TestPathInfoCACompatibility124=== RUN TestPathInfoCACompatibility/null_ca_field125=== PAUSE TestPathInfoCACompatibility/null_ca_field126=== RUN TestPathInfoCACompatibility/old_string_format_-_text127=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text128--- PASS: TestFileTokenEmpty (0.00s)129=== CONT TestParsePathInfoJSONMultiplePaths130=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive131=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths1322026/09/16 23:49:29 WARN Rate limiter enabled after throttle name=server-test rate=5133=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths134=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive135=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths136=== RUN TestPathInfoCACompatibility/new_structured_format_-_text137=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths138=== CONT TestParsePathInfoJSON139=== RUN TestParsePathInfoJSON/Nix_format140=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text141=== PAUSE TestParsePathInfoJSON/Nix_format142=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method143=== RUN TestParsePathInfoJSON/Lix_format144=== PAUSE TestParsePathInfoJSON/Lix_format145=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method146=== CONT TestPathInfoHashCompatibility147=== RUN TestParsePathInfoJSON/empty_input148=== PAUSE TestParsePathInfoJSON/empty_input149=== RUN TestParsePathInfoJSON/whitespace_only150=== PAUSE TestParsePathInfoJSON/whitespace_only151=== RUN TestParsePathInfoJSON/invalid_JSON152=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)153=== PAUSE TestParsePathInfoJSON/invalid_JSON154=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)155=== CONT TestGetStorePathHash156=== RUN TestGetStorePathHash/valid_store_path157=== PAUSE TestGetStorePathHash/valid_store_path158=== RUN TestGetStorePathHash/basename_without_hyphen_should_error159=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error160=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error161=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error162=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error163=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error164=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon165=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon166=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI167=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI168=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512169=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512170=== CONT TestStreamPushGivesUpOnDeadServer1712026/09/16 23:49:29 ERROR Upload failed error="connection refused" count=201722026/09/16 23:49:29 ERROR Server seems unavailable, giving up on batch untried=17173=== CONT TestSetClientTLSErrors174--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)175=== CONT TestSetClientTLSDoesNotMutateDefaultTransport1762026/09/16 23:49:29 WARN Rate limiter enabled after throttle name=server-test rate=51772026/09/16 23:49:29 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:61001178--- PASS: TestScriptTokenScriptFails (0.01s)179=== CONT TestSetClientTLS180--- PASS: TestDoServerRequestAttachesToken (0.01s)181=== CONT TestStreamPushRequestLine1822026/09/16 23:49:29 WARN Rate limiter backed off name=server-test rate=51832026/09/16 23:49:29 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:61001184=== RUN TestSetClientTLSErrors/missing_cert_file185=== PAUSE TestSetClientTLSErrors/missing_cert_file186=== RUN TestSetClientTLSErrors/missing_key_file187=== PAUSE TestSetClientTLSErrors/missing_key_file188=== RUN TestSetClientTLSErrors/missing_ca_file189=== PAUSE TestSetClientTLSErrors/missing_ca_file190=== RUN TestSetClientTLSErrors/invalid_ca_file191=== PAUSE TestSetClientTLSErrors/invalid_ca_file192=== CONT TestDumpPathMatchesNix1932026/09/16 23:49:29 ERROR Upload failed error="stale build claim" count=1194--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.01s)195=== CONT TestEncodeNixBase32WithRealHash196--- PASS: TestEncodeNixBase32WithRealHash (0.00s)197=== CONT TestEncodeNixBase32198=== RUN TestEncodeNixBase32/test_string_hash199=== PAUSE TestEncodeNixBase32/test_string_hash200=== RUN TestEncodeNixBase32/empty_input201=== PAUSE TestEncodeNixBase32/empty_input202=== CONT TestDumpPathWriterError203--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.00s)204=== CONT TestDumpPathSingleFile205=== RUN TestSetClientTLS/rejects_connection_without_client_cert206=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert207=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA208=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA209=== RUN TestSetClientTLS/preserves_debug_logging_transport210=== PAUSE TestSetClientTLS/preserves_debug_logging_transport211=== CONT TestPartSizeForNAR212=== RUN TestPartSizeForNAR/zero_stays_at_minimum213=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum214=== RUN TestPartSizeForNAR/small_stays_at_minimum215=== PAUSE TestPartSizeForNAR/small_stays_at_minimum216=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum217=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum218=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts219=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts220=== RUN TestPartSizeForNAR/1_TiB221=== PAUSE TestPartSizeForNAR/1_TiB222=== RUN TestPartSizeForNAR/5_TiB_S3_max_object223=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object224=== RUN TestPartSizeForNAR/capped_at_5_GiB225=== PAUSE TestPartSizeForNAR/capped_at_5_GiB226=== CONT TestStreamPushBatchesUnderLoad227--- PASS: TestScriptTokenBadJSON (0.01s)228=== CONT TestStreamPushIsolatesFailures2292026/09/16 23:49:29 ERROR Upload failed error="bad path" count=3230--- PASS: TestStreamPushIsolatesFailures (0.00s)231=== CONT TestStreamPushReportsEveryPath232--- PASS: TestStreamPushReportsEveryPath (0.00s)233=== CONT TestShellSplitErrors234--- PASS: TestShellSplitErrors (0.00s)235=== CONT TestFilterOversizedClosures236=== RUN TestFilterOversizedClosures/no_limit_keeps_everything237=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything238=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped239=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped240=== RUN TestFilterOversizedClosures/all_closures_skipped241=== PAUSE TestFilterOversizedClosures/all_closures_skipped242=== CONT TestCaseHackSuffix243--- PASS: TestScriptTokenEmptyToken (0.01s)244=== CONT TestUploadMultipart_SupersededByPeer245=== RUN TestUploadMultipart_SupersededByPeer/exists246=== PAUSE TestUploadMultipart_SupersededByPeer/exists247=== RUN TestUploadMultipart_SupersededByPeer/missing248=== PAUSE TestUploadMultipart_SupersededByPeer/missing249=== CONT TestConvertHashToNix32/SRI_format_to_Nix32250=== CONT TestConvertHashToNix32/invalid_format251=== CONT TestConvertHashToNix32/already_Nix32_format252--- PASS: TestConvertHashToNix32 (0.00s)253 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)254 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)255 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)256=== CONT TestRateLimiterFeedback/429_enables_limiter2572026/09/16 23:49:29 WARN Rate limiter enabled after throttle name=server-test rate=52582026/09/16 23:49:29 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:610072592026/09/16 23:49:29 WARN Rate limiter backed off name=server-test rate=5260=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter261=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter262=== CONT TestRateLimiterFeedback/503_enables_limiter2632026/09/16 23:49:29 WARN Rate limiter enabled after throttle name=server-test rate=52642026/09/16 23:49:29 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:610132652026/09/16 23:49:29 WARN Rate limiter backed off name=server-test rate=5266--- PASS: TestRateLimiterFeedback (0.00s)267 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)268 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)269 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)270 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)271=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths272=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths273--- PASS: TestParsePathInfoJSONMultiplePaths (0.00s)274 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)275 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)276=== CONT TestPathInfoCACompatibility/null_ca_field277=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method278=== CONT TestPathInfoCACompatibility/new_structured_format_-_text279=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive280=== CONT TestPathInfoCACompatibility/old_string_format_-_text281--- PASS: TestPathInfoCACompatibility (0.00s)282 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)283 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)284 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)285 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)286 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)287=== CONT TestParsePathInfoJSON/Nix_format288=== CONT TestParsePathInfoJSON/whitespace_only289=== CONT TestParsePathInfoJSON/invalid_JSON290=== CONT TestParsePathInfoJSON/empty_input291=== CONT TestParsePathInfoJSON/Lix_format292--- PASS: TestParsePathInfoJSON (0.00s)293 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)294 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)295 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)296 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)297 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)298=== CONT TestGetStorePathHash/valid_store_path299=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)300=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error301=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error302=== CONT TestGetStorePathHash/basename_without_hyphen_should_error303--- PASS: TestGetStorePathHash (0.00s)304 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)305 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)306 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)307 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)308=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI309=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512310=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon311--- PASS: TestPathInfoHashCompatibility (0.00s)312 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)313 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)314 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)315 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)316=== CONT TestSetClientTLSErrors/missing_cert_file317=== CONT TestSetClientTLSErrors/missing_ca_file318=== CONT TestSetClientTLSErrors/invalid_ca_file319=== CONT TestSetClientTLSErrors/missing_key_file320=== CONT TestEncodeNixBase32/test_string_hash321=== CONT TestEncodeNixBase32/empty_input322--- PASS: TestEncodeNixBase32 (0.00s)323 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)324 --- PASS: TestEncodeNixBase32/empty_input (0.00s)325=== CONT TestSetClientTLS/rejects_connection_without_client_cert326--- PASS: TestSetClientTLSErrors (0.00s)327 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)328 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)329 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)330 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)331--- PASS: TestStreamPushRequestLine (0.01s)332=== CONT TestSetClientTLS/preserves_debug_logging_transport333=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA334=== CONT TestPartSizeForNAR/zero_stays_at_minimum335=== CONT TestPartSizeForNAR/capped_at_5_GiB336=== CONT TestPartSizeForNAR/5_TiB_S3_max_object337=== CONT TestPartSizeForNAR/1_TiB338=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts339=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum340=== CONT TestPartSizeForNAR/small_stays_at_minimum341--- PASS: TestPartSizeForNAR (0.00s)342 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)343 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)344 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)345 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)346 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)347 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)348 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)349=== CONT TestFilterOversizedClosures/no_limit_keeps_everything350=== CONT TestFilterOversizedClosures/all_closures_skipped3512026/09/16 23:49:29 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=50352=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped3532026/09/16 23:49:29 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=2000354--- PASS: TestFilterOversizedClosures (0.00s)355 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)356 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)357 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)358=== CONT TestUploadMultipart_SupersededByPeer/exists359=== CONT TestUploadMultipart_SupersededByPeer/missing360--- PASS: TestUploadMultipart_SupersededByPeer (0.00s)361 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)362 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)363--- PASS: TestScriptTokenCachesUntilRefresh (0.03s)364--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.03s)3652026/09/16 23:49:29 http: TLS handshake error from 127.0.0.1:61015: read tcp 127.0.0.1:61006->127.0.0.1:61015: use of closed network connection366--- PASS: TestSetClientTLS (0.00s)367 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.00s)368 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.00s)369 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.02s)370--- PASS: TestDumpPathWriterError (0.03s)371--- PASS: TestDumpPathSingleFile (0.06s)372--- PASS: TestCaseHackSuffix (0.05s)373--- PASS: TestDumpPathMatchesNix (0.08s)374--- PASS: TestStreamPushBatchesUnderLoad (0.10s)375--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.01s)376PASS377Running server tests...378The files belonging to this database system will be owned by user "_nixbld10".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-62631-4145625453/postgres1508681291/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-62631-4145625453/postgres1508681291/data -l logfile start4044052026-09-16 23:49:31.608 UTC [62919] LOG: starting PostgreSQL 18.6 on aarch64-apple-darwin25.6.0, compiled by clang version 21.1.8, 64-bit4062026-09-16 23:49:31.608 UTC [62919] LOG: listening on Unix socket "/nix/var/nix/builds/nix-62631-4145625453/postgres1508681291/.s.PGSQL.5432"4072026-09-16 23:49:31.617 UTC [62926] LOG: database system was shut down at 2026-09-16 23:49:31 UTC4082026-09-16 23:49:31.622 UTC [62927] FATAL: the database system is starting up4092026-09-16 23:49:31.623 UTC [62919] LOG: database system is ready to accept connections410/nix/var/nix/builds/nix-62631-4145625453/postgres1508681291:5432 - rejecting connections411/nix/var/nix/builds/nix-62631-4145625453/postgres1508681291:5432 - accepting connections412=== RUN TestService_AuthMiddleware413=== PAUSE TestService_AuthMiddleware414=== RUN TestService_AuthMiddleware_MTLSProxyHeader415=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader416=== RUN TestService_AuthMiddleware_MTLSBoundSubjects417=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects418=== RUN TestService_ReadAuthMiddleware419=== PAUSE TestService_ReadAuthMiddleware420=== RUN TestService_AuthMiddleware_OIDC421=== PAUSE TestService_AuthMiddleware_OIDC422=== RUN TestService_RequireScope_OIDC423=== PAUSE TestService_RequireScope_OIDC424=== RUN TestService_ReadScope_PublicByDefault425=== PAUSE TestService_ReadScope_PublicByDefault426=== RUN TestCacheConfigHandler427=== PAUSE TestCacheConfigHandler428=== RUN TestCacheStatsHandler429=== PAUSE TestCacheStatsHandler430=== RUN TestClaim_BuildWaitComplete431=== PAUSE TestClaim_BuildWaitComplete432=== RUN TestClaim_GCMarkedOutputCountsAsAbsent433=== PAUSE TestClaim_GCMarkedOutputCountsAsAbsent434=== RUN TestClaim_TooManyStreams435=== PAUSE TestClaim_TooManyStreams436=== RUN TestClaim_HolderDisconnectKeepsClaim437=== PAUSE TestClaim_HolderDisconnectKeepsClaim438=== RUN TestClaim_FailWakesWaitersButIsNotRemembered439=== PAUSE TestClaim_FailWakesWaitersButIsNotRemembered440=== RUN TestClaim_FailWithoutKindReleases441=== PAUSE TestClaim_FailWithoutKindReleases442=== RUN TestClaim_StaleHeartbeatStolen443=== PAUSE TestClaim_StaleHeartbeatStolen444=== RUN TestClaim_TwoInstances445=== PAUSE TestClaim_TwoInstances446=== RUN TestClaim_InputsTouched447=== PAUSE TestClaim_InputsTouched448=== RUN TestClaim_StreamsThroughServer449=== PAUSE TestClaim_StreamsThroughServer450=== RUN TestPresent451=== PAUSE TestPresent452=== RUN TestClientCADerivations453=== PAUSE TestClientCADerivations454=== RUN TestClientErrorHandling455=== PAUSE TestClientErrorHandling456=== RUN TestClientIntegration457=== PAUSE TestClientIntegration458=== RUN TestClientMultipleUploads459=== PAUSE TestClientMultipleUploads460=== RUN TestClientWithDependencies461=== PAUSE TestClientWithDependencies462=== RUN TestPinProtectsFromGC463=== PAUSE TestPinProtectsFromGC464=== RUN TestResolveDBConnectionString465=== PAUSE TestResolveDBConnectionString466=== RUN TestGCAdvisoryLockBlocksConcurrentRun4672026-09-16 23:49:32.292 UTC [62945] ERROR: relation "goose_db_version" does not exist at character 364682026-09-16 23:49:32.292 UTC [62945] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC4692026/09/16 23:49:32 OK 20241026095416_initial_model.sql (16.09ms)4702026/09/16 23:49:32 OK 20251210153512_drop_unused_gin_index.sql (11.2ms)4712026/09/16 23:49:32 OK 20251218171726_add_pins.sql (7.25ms)4722026/09/16 23:49:32 OK 20260628120000_add_object_size_and_stats.sql (8.66ms)4732026/09/16 23:49:32 OK 20260905000000_add_claims.sql (8.17ms)4742026/09/16 23:49:32 goose: successfully migrated database to version: 202609050000004752026/09/16 23:49:32 OK 1_commit_pending_closure.sql (6.79ms)4762026/09/16 23:49:32 OK 2_object_stats_trigger.sql (9.11ms)4772026/09/16 23:49:32 goose: up to current file version: 2478--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.46s)479=== RUN TestGCBugBareHashReferences480=== PAUSE TestGCBugBareHashReferences481=== RUN TestGCMetrics482=== PAUSE TestGCMetrics483=== RUN TestGCTaskStore_StartNew484=== PAUSE TestGCTaskStore_StartNew485=== RUN TestGCTaskStore_DeduplicateSameParams486=== PAUSE TestGCTaskStore_DeduplicateSameParams487=== RUN TestGCTaskStore_ConflictDifferentParams488=== PAUSE TestGCTaskStore_ConflictDifferentParams489=== RUN TestGCTaskStore_GetEmpty490=== PAUSE TestGCTaskStore_GetEmpty491=== RUN TestGCTaskStore_GetReturnsLatest492=== PAUSE TestGCTaskStore_GetReturnsLatest493=== RUN TestGCTaskStore_CompletedAllowsNewTask494=== PAUSE TestGCTaskStore_CompletedAllowsNewTask495=== RUN TestGCTaskStore_PhaseUpdates496=== PAUSE TestGCTaskStore_PhaseUpdates497=== RUN TestGCTaskStore_Fail498=== PAUSE TestGCTaskStore_Fail499=== RUN TestGracefulShutdownDrainsInflight500=== PAUSE TestGracefulShutdownDrainsInflight501=== RUN TestService_healthCheckHandler502=== PAUSE TestService_healthCheckHandler503=== RUN TestService_readinessHandler504=== PAUSE TestService_readinessHandler505=== RUN TestGenerateLandingPage506=== PAUSE TestGenerateLandingPage507=== RUN TestCacheConfigHandlerMaxNarSize508=== PAUSE TestCacheConfigHandlerMaxNarSize509=== RUN TestCreatePendingClosureRejectsOversizedNAR510=== PAUSE TestCreatePendingClosureRejectsOversizedNAR511=== RUN TestNARDeduplicationMetadataUploadBug512=== PAUSE TestNARDeduplicationMetadataUploadBug513=== RUN TestMetricsInventory514=== PAUSE TestMetricsInventory515=== RUN TestService_NativeMTLS516=== PAUSE TestService_NativeMTLS517=== RUN TestServerTLSConfig518=== PAUSE TestServerTLSConfig519=== RUN TestMultipartCleanup520=== PAUSE TestMultipartCleanup521=== RUN TestObjectStatsTrigger522=== PAUSE TestObjectStatsTrigger523=== RUN TestOrphanedObjectsGC524=== PAUSE TestOrphanedObjectsGC525=== RUN TestOrphanedObjectsGCStressTest526=== PAUSE TestOrphanedObjectsGCStressTest527=== RUN TestResurrectedObjectNotDeleted528=== PAUSE TestResurrectedObjectNotDeleted529=== RUN TestParseSingleRange530=== PAUSE TestParseSingleRange531=== RUN TestIsValidCachePath532=== PAUSE TestIsValidCachePath533=== RUN TestReadProxyNarinfo534=== PAUSE TestReadProxyNarinfo535=== RUN TestReadProxyNarinfoAlreadyDecompressed536=== PAUSE TestReadProxyNarinfoAlreadyDecompressed537=== RUN TestReadProxyNarStreaming538=== PAUSE TestReadProxyNarStreaming539=== RUN TestReadProxy404540=== PAUSE TestReadProxy404541=== RUN TestReadProxyInvalidPath542=== PAUSE TestReadProxyInvalidPath543=== RUN TestReadProxyHead544=== PAUSE TestReadProxyHead545=== RUN TestReadProxyConditionalGet546=== PAUSE TestReadProxyConditionalGet547=== RUN TestReadProxyRootRedirectsToIndexHTML548=== PAUSE TestReadProxyRootRedirectsToIndexHTML549=== RUN TestReadProxyDisabled550=== PAUSE TestReadProxyDisabled551=== RUN TestReadRedirectNar552=== PAUSE TestReadRedirectNar553=== RUN TestReadRedirectKeepsNarinfoProxied554=== PAUSE TestReadRedirectKeepsNarinfoProxied555=== RUN TestReadProxyRangeRequest556=== PAUSE TestReadProxyRangeRequest557=== RUN TestReadRedirectUsesPublicS3URL558=== PAUSE TestReadRedirectUsesPublicS3URL559=== RUN TestRedundantMultipartUpload560=== PAUSE TestRedundantMultipartUpload561=== RUN TestCompleteMultipartUpload_ErrorButObjectExists562=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists563=== RUN TestCompletedNarNotReofferedAcrossClosures564=== PAUSE TestCompletedNarNotReofferedAcrossClosures565=== RUN TestPresignedUploadRegisteredBeforeCommit566=== PAUSE TestPresignedUploadRegisteredBeforeCommit567=== RUN TestService_Rustfstest568=== PAUSE TestService_Rustfstest569=== RUN TestParseSize570=== PAUSE TestParseSize571=== RUN TestSkippedUploadsHandler572=== PAUSE TestSkippedUploadsHandler573=== RUN TestSystemdListenerNotActivated574--- PASS: TestSystemdListenerNotActivated (0.00s)575=== RUN TestWatchdogBeatsWhenHealthy576--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)577=== RUN TestWatchdogSkipsWhenUnhealthy5782026/09/16 23:49:32 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5792026/09/16 23:49:32 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5802026/09/16 23:49:32 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5812026/09/16 23:49:32 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5822026/09/16 23:49:32 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5832026/09/16 23:49:32 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5842026/09/16 23:49:32 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5852026/09/16 23:49:32 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5862026/09/16 23:49:32 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5872026/09/16 23:49:32 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"588--- PASS: TestWatchdogSkipsWhenUnhealthy (0.21s)589=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle590=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle591=== RUN TestProxyWriteTimeout592=== PAUSE TestProxyWriteTimeout593=== RUN TestIsValidUploadKey594=== PAUSE TestIsValidUploadKey595=== RUN TestUploadHandlersRejectInvalidKeys596=== PAUSE TestUploadHandlersRejectInvalidKeys597=== RUN TestUploadHandlersRejectOversizedBody598=== PAUSE TestUploadHandlersRejectOversizedBody599=== RUN TestService_cleanupPendingClosuresHandler600=== PAUSE TestService_cleanupPendingClosuresHandler601=== RUN TestService_createPendingClosureHandler602=== PAUSE TestService_createPendingClosureHandler603=== RUN TestService_verifyS3Integrity604=== PAUSE TestService_verifyS3Integrity605=== RUN TestCompleteMultipartUnregistered606=== PAUSE TestCompleteMultipartUnregistered607=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT608=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT609=== CONT TestService_AuthMiddleware610=== CONT TestCreatePendingClosureRejectsOversizedNAR6112026/09/16 23:49:32 INFO Received uploads request method=POST path=/api/pending_closures612=== CONT TestClientErrorHandling613--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)614=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT615=== RUN TestClientErrorHandling/InvalidStorePath616=== PAUSE TestClientErrorHandling/InvalidStorePath617=== RUN TestClientErrorHandling/InvalidAuthToken618=== PAUSE TestClientErrorHandling/InvalidAuthToken619=== RUN TestClientErrorHandling/ServerNotAvailable620=== PAUSE TestClientErrorHandling/ServerNotAvailable621=== CONT TestClientErrorHandling/InvalidStorePath622=== CONT TestCacheConfigHandlerMaxNarSize623=== CONT TestCompleteMultipartUnregistered624--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)625=== CONT TestGenerateLandingPage626=== CONT TestService_verifyS3Integrity627=== CONT TestService_createPendingClosureHandler628=== CONT TestService_cleanupPendingClosuresHandler629=== CONT TestUploadHandlersRejectOversizedBody630=== CONT TestGCTaskStore_PhaseUpdates631--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)632=== CONT TestGCTaskStore_DeduplicateSameParams633--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)634=== CONT TestGCTaskStore_CompletedAllowsNewTask635--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)636=== CONT TestGCTaskStore_GetReturnsLatest637--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)638=== CONT TestGCTaskStore_GetEmpty639--- PASS: TestGCTaskStore_GetEmpty (0.00s)640=== CONT TestGCTaskStore_ConflictDifferentParams641--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)642=== CONT TestClaim_TooManyStreams643--- PASS: TestGenerateLandingPage (0.01s)644=== CONT TestClientCADerivations645=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure646=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure647=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart648=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart649=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts650=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts651=== CONT TestPresent6522026-09-16 23:49:32.978 UTC [63052] ERROR: relation "goose_db_version" does not exist at character 366532026-09-16 23:49:32.978 UTC [63052] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6542026-09-16 23:49:33.009 UTC [63053] ERROR: relation "goose_db_version" does not exist at character 366552026-09-16 23:49:33.009 UTC [63053] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6562026-09-16 23:49:33.014 UTC [63054] ERROR: relation "goose_db_version" does not exist at character 366572026-09-16 23:49:33.014 UTC [63054] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6582026-09-16 23:49:33.021 UTC [63055] ERROR: relation "goose_db_version" does not exist at character 366592026-09-16 23:49:33.021 UTC [63055] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6602026-09-16 23:49:33.029 UTC [63056] ERROR: relation "goose_db_version" does not exist at character 366612026-09-16 23:49:33.029 UTC [63056] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6622026/09/16 23:49:33 OK 20241026095416_initial_model.sql (6.55ms)6632026/09/16 23:49:33 OK 20241026095416_initial_model.sql (6.89ms)6642026/09/16 23:49:33 OK 20251210153512_drop_unused_gin_index.sql (1.94ms)6652026/09/16 23:49:33 OK 20251210153512_drop_unused_gin_index.sql (2.11ms)6662026/09/16 23:49:33 OK 20241026095416_initial_model.sql (9.3ms)6672026/09/16 23:49:33 OK 20251218171726_add_pins.sql (3.49ms)6682026/09/16 23:49:33 OK 20251218171726_add_pins.sql (3.07ms)6692026/09/16 23:49:33 OK 20241026095416_initial_model.sql (9.52ms)6702026/09/16 23:49:33 OK 20251210153512_drop_unused_gin_index.sql (874.71µs)6712026/09/16 23:49:33 OK 20241026095416_initial_model.sql (8.51ms)6722026/09/16 23:49:33 OK 20251210153512_drop_unused_gin_index.sql (924.17µs)6732026-09-16 23:49:33.049 UTC [63058] ERROR: relation "goose_db_version" does not exist at character 366742026-09-16 23:49:33.049 UTC [63058] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6752026/09/16 23:49:33 OK 20260628120000_add_object_size_and_stats.sql (2.38ms)6762026/09/16 23:49:33 OK 20251210153512_drop_unused_gin_index.sql (1.25ms)6772026/09/16 23:49:33 OK 20260628120000_add_object_size_and_stats.sql (2.63ms)6782026/09/16 23:49:33 OK 20251218171726_add_pins.sql (2.22ms)6792026/09/16 23:49:33 OK 20251218171726_add_pins.sql (1.82ms)6802026/09/16 23:49:33 OK 20251218171726_add_pins.sql (1.59ms)6812026/09/16 23:49:33 OK 20260905000000_add_claims.sql (1.97ms)6822026/09/16 23:49:33 goose: successfully migrated database to version: 202609050000006832026/09/16 23:49:33 OK 20260628120000_add_object_size_and_stats.sql (1.66ms)6842026/09/16 23:49:33 OK 20260628120000_add_object_size_and_stats.sql (1.77ms)6852026/09/16 23:49:33 OK 20260905000000_add_claims.sql (2.75ms)6862026/09/16 23:49:33 goose: successfully migrated database to version: 202609050000006872026/09/16 23:49:33 OK 1_commit_pending_closure.sql (1.6ms)6882026/09/16 23:49:33 OK 20260905000000_add_claims.sql (1.55ms)6892026/09/16 23:49:33 goose: successfully migrated database to version: 202609050000006902026/09/16 23:49:33 OK 2_object_stats_trigger.sql (734.46µs)6912026/09/16 23:49:33 goose: up to current file version: 26922026/09/16 23:49:33 OK 20260628120000_add_object_size_and_stats.sql (2.82ms)6932026/09/16 23:49:33 OK 20260905000000_add_claims.sql (2.05ms)6942026/09/16 23:49:33 goose: successfully migrated database to version: 202609050000006952026/09/16 23:49:33 OK 1_commit_pending_closure.sql (2.44ms)6962026/09/16 23:49:33 OK 1_commit_pending_closure.sql (3.12ms)6972026/09/16 23:49:33 OK 20260905000000_add_claims.sql (1.61ms)6982026/09/16 23:49:33 goose: successfully migrated database to version: 202609050000006992026/09/16 23:49:33 OK 1_commit_pending_closure.sql (2.26ms)7002026/09/16 23:49:33 OK 2_object_stats_trigger.sql (919.83µs)7012026/09/16 23:49:33 goose: up to current file version: 27022026/09/16 23:49:33 OK 2_object_stats_trigger.sql (848.67µs)7032026/09/16 23:49:33 goose: up to current file version: 27042026/09/16 23:49:33 OK 20241026095416_initial_model.sql (3.75ms)7052026/09/16 23:49:33 OK 1_commit_pending_closure.sql (1.16ms)7062026/09/16 23:49:33 OK 2_object_stats_trigger.sql (540.17µs)7072026/09/16 23:49:33 goose: up to current file version: 27082026/09/16 23:49:33 OK 2_object_stats_trigger.sql (277.58µs)7092026/09/16 23:49:33 goose: up to current file version: 27102026/09/16 23:49:33 OK 20251210153512_drop_unused_gin_index.sql (800.46µs)7112026-09-16 23:49:33.060 UTC [63065] ERROR: relation "goose_db_version" does not exist at character 367122026-09-16 23:49:33.060 UTC [63065] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7132026/09/16 23:49:33 OK 20251218171726_add_pins.sql (2.38ms)7142026/09/16 23:49:33 OK 20260628120000_add_object_size_and_stats.sql (6.74ms)7152026/09/16 23:49:33 OK 20260905000000_add_claims.sql (26.37ms)7162026/09/16 23:49:33 goose: successfully migrated database to version: 202609050000007172026/09/16 23:49:33 OK 1_commit_pending_closure.sql (2.48ms)7182026/09/16 23:49:33 OK 2_object_stats_trigger.sql (652.63µs)7192026/09/16 23:49:33 goose: up to current file version: 27202026/09/16 23:49:33 OK 20241026095416_initial_model.sql (30.77ms)7212026-09-16 23:49:33.112 UTC [63068] ERROR: relation "goose_db_version" does not exist at character 367222026-09-16 23:49:33.112 UTC [63068] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7232026/09/16 23:49:33 OK 20251210153512_drop_unused_gin_index.sql (6.68ms)7242026-09-16 23:49:33.113 UTC [63067] ERROR: relation "goose_db_version" does not exist at character 367252026-09-16 23:49:33.113 UTC [63067] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7262026/09/16 23:49:33 OK 20251218171726_add_pins.sql (8.29ms)7272026/09/16 23:49:33 OK 20260628120000_add_object_size_and_stats.sql (14.9ms)7282026/09/16 23:49:33 OK 20260905000000_add_claims.sql (11.91ms)7292026/09/16 23:49:33 goose: successfully migrated database to version: 202609050000007302026/09/16 23:49:33 OK 1_commit_pending_closure.sql (9.36ms)7312026/09/16 23:49:33 OK 2_object_stats_trigger.sql (9.41ms)7322026/09/16 23:49:33 goose: up to current file version: 27332026/09/16 23:49:33 OK 20241026095416_initial_model.sql (34.7ms)7342026/09/16 23:49:33 OK 20241026095416_initial_model.sql (41.54ms)7352026/09/16 23:49:33 OK 20251210153512_drop_unused_gin_index.sql (12.68ms)7362026-09-16 23:49:33.184 UTC [63071] ERROR: relation "goose_db_version" does not exist at character 367372026-09-16 23:49:33.184 UTC [63071] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7382026/09/16 23:49:33 OK 20251210153512_drop_unused_gin_index.sql (15.35ms)7392026/09/16 23:49:33 OK 20251218171726_add_pins.sql (12.97ms)7402026/09/16 23:49:33 OK 20251218171726_add_pins.sql (12.04ms)7412026/09/16 23:49:33 OK 20260628120000_add_object_size_and_stats.sql (4.62ms)7422026/09/16 23:49:33 OK 20260628120000_add_object_size_and_stats.sql (13.73ms)7432026/09/16 23:49:33 OK 20260905000000_add_claims.sql (18.96ms)7442026/09/16 23:49:33 goose: successfully migrated database to version: 202609050000007452026/09/16 23:49:33 OK 20260905000000_add_claims.sql (22.46ms)7462026/09/16 23:49:33 goose: successfully migrated database to version: 202609050000007472026/09/16 23:49:33 INFO Received uploads request method=POST path=/api/pending_closures7482026/09/16 23:49:33 OK 1_commit_pending_closure.sql (12.58ms)7492026/09/16 23:49:33 OK 20241026095416_initial_model.sql (21.88ms)7502026/09/16 23:49:33 OK 1_commit_pending_closure.sql (10.61ms)7512026/09/16 23:49:33 OK 2_object_stats_trigger.sql (5.49ms)7522026/09/16 23:49:33 goose: up to current file version: 27532026/09/16 23:49:33 OK 20251210153512_drop_unused_gin_index.sql (8.57ms)7542026/09/16 23:49:33 OK 2_object_stats_trigger.sql (12.86ms)7552026/09/16 23:49:33 goose: up to current file version: 27562026/09/16 23:49:33 OK 20251218171726_add_pins.sql (12.57ms)7572026/09/16 23:49:33 OK 20260628120000_add_object_size_and_stats.sql (5.85ms)7582026/09/16 23:49:33 OK 20260905000000_add_claims.sql (25.47ms)7592026/09/16 23:49:33 goose: successfully migrated database to version: 202609050000007602026/09/16 23:49:33 OK 1_commit_pending_closure.sql (7.33ms)7612026/09/16 23:49:33 OK 2_object_stats_trigger.sql (557.46µs)7622026/09/16 23:49:33 goose: up to current file version: 2763--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.59s)764=== CONT TestClaim_StreamsThroughServer7652026/09/16 23:49:33 INFO Received complete multipart upload request method=POST path=/api/multipart/complete7662026/09/16 23:49:33 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst767--- PASS: TestCompleteMultipartUnregistered (0.69s)768=== CONT TestClaim_InputsTouched7692026-09-16 23:49:33.490 UTC [63090] ERROR: relation "goose_db_version" does not exist at character 367702026-09-16 23:49:33.490 UTC [63090] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7712026/09/16 23:49:33 OK 20241026095416_initial_model.sql (27.79ms)7722026-09-16 23:49:33.565 UTC [63091] ERROR: relation "goose_db_version" does not exist at character 367732026-09-16 23:49:33.565 UTC [63091] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7742026/09/16 23:49:33 OK 20251210153512_drop_unused_gin_index.sql (12.55ms)7752026/09/16 23:49:33 OK 20251218171726_add_pins.sql (12.53ms)7762026/09/16 23:49:33 OK 20260628120000_add_object_size_and_stats.sql (10.77ms)7772026/09/16 23:49:33 OK 20260905000000_add_claims.sql (13.82ms)7782026/09/16 23:49:33 goose: successfully migrated database to version: 202609050000007792026/09/16 23:49:33 OK 20241026095416_initial_model.sql (28.91ms)7802026/09/16 23:49:33 OK 1_commit_pending_closure.sql (14.31ms)7812026/09/16 23:49:33 OK 2_object_stats_trigger.sql (8.46ms)7822026/09/16 23:49:33 goose: up to current file version: 27832026/09/16 23:49:33 OK 20251210153512_drop_unused_gin_index.sql (17.48ms)7842026/09/16 23:49:33 OK 20251218171726_add_pins.sql (13.68ms)7852026/09/16 23:49:33 OK 20260628120000_add_object_size_and_stats.sql (9.98ms)7862026/09/16 23:49:33 OK 20260905000000_add_claims.sql (13.12ms)7872026/09/16 23:49:33 goose: successfully migrated database to version: 202609050000007882026/09/16 23:49:33 OK 1_commit_pending_closure.sql (5.9ms)7892026/09/16 23:49:33 OK 2_object_stats_trigger.sql (635.88µs)7902026/09/16 23:49:33 goose: up to current file version: 27912026/09/16 23:49:33 INFO Received uploads request method=POST path=/api/pending_closures7922026/09/16 23:49:33 INFO Received uploads request method=POST path=/api/pending_closures7932026/09/16 23:49:33 INFO Received uploads request method=POST path=/api/pending_closures7942026/09/16 23:49:33 INFO Received cleanup request method=DELETE path=/api/pending_closures7952026/09/16 23:49:33 INFO Aborted multipart uploads count=07962026/09/16 23:49:33 INFO Received uploads request method=POST path=/api/pending_closures7972026/09/16 23:49:33 INFO Received cleanup request method=DELETE path=/api/pending_closures7982026/09/16 23:49:33 INFO Aborted multipart uploads count=17992026/09/16 23:49:33 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete8002026-09-16 23:49:33.952 UTC [63056] ERROR: Closure does not exist: id=18012026-09-16 23:49:33.952 UTC [63056] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 16 at RAISE8022026-09-16 23:49:33.952 UTC [63056] STATEMENT: -- name: CommitPendingClosure :exec803 SELECT commit_pending_closure($1::bigint)804 805--- PASS: TestService_cleanupPendingClosuresHandler (1.23s)806=== CONT TestClaim_TwoInstances8072026-09-16 23:49:34.126 UTC [63098] ERROR: relation "goose_db_version" does not exist at character 368082026-09-16 23:49:34.126 UTC [63098] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC809=== CONT TestClaim_StaleHeartbeatStolen8102026/09/16 23:49:34 OK 20241026095416_initial_model.sql (51.7ms)8112026/09/16 23:49:34 OK 20251210153512_drop_unused_gin_index.sql (11.17ms)8122026/09/16 23:49:34 OK 20251218171726_add_pins.sql (8.85ms)8132026/09/16 23:49:34 OK 20260628120000_add_object_size_and_stats.sql (9.49ms)8142026/09/16 23:49:34 OK 20260905000000_add_claims.sql (33.85ms)8152026/09/16 23:49:34 goose: successfully migrated database to version: 202609050000008162026/09/16 23:49:34 OK 1_commit_pending_closure.sql (4.88ms)8172026/09/16 23:49:34 OK 2_object_stats_trigger.sql (270.29µs)8182026/09/16 23:49:34 goose: up to current file version: 28192026/09/16 23:49:34 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"820--- PASS: TestService_AuthMiddleware (1.59s)821=== CONT TestClaim_FailWithoutKindReleases8222026-09-16 23:49:34.344 UTC [63103] ERROR: relation "goose_db_version" does not exist at character 368232026-09-16 23:49:34.344 UTC [63103] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8242026/09/16 23:49:34 OK 20241026095416_initial_model.sql (27.37ms)8252026/09/16 23:49:34 OK 20251210153512_drop_unused_gin_index.sql (5.86ms)8262026/09/16 23:49:34 OK 20251218171726_add_pins.sql (18.82ms)8272026/09/16 23:49:34 OK 20260628120000_add_object_size_and_stats.sql (24.37ms)8282026/09/16 23:49:34 OK 20260905000000_add_claims.sql (21.48ms)8292026/09/16 23:49:34 goose: successfully migrated database to version: 202609050000008302026/09/16 23:49:34 OK 1_commit_pending_closure.sql (1.57ms)8312026/09/16 23:49:34 OK 2_object_stats_trigger.sql (286.04µs)8322026/09/16 23:49:34 goose: up to current file version: 28332026-09-16 23:49:34.576 UTC [63106] ERROR: relation "goose_db_version" does not exist at character 368342026-09-16 23:49:34.576 UTC [63106] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8352026/09/16 23:49:34 OK 20241026095416_initial_model.sql (25.21ms)8362026/09/16 23:49:34 OK 20251210153512_drop_unused_gin_index.sql (10.46ms)8372026/09/16 23:49:34 OK 20251218171726_add_pins.sql (13.14ms)8382026/09/16 23:49:34 OK 20260628120000_add_object_size_and_stats.sql (9.25ms)8392026/09/16 23:49:34 OK 20260905000000_add_claims.sql (16.97ms)8402026/09/16 23:49:34 goose: successfully migrated database to version: 202609050000008412026/09/16 23:49:34 OK 1_commit_pending_closure.sql (1.98ms)8422026/09/16 23:49:34 OK 2_object_stats_trigger.sql (296.38µs)8432026/09/16 23:49:34 goose: up to current file version: 28442026/09/16 23:49:34 INFO Received complete multipart upload request method=POST path=/api/multipart/complete8452026/09/16 23:49:34 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=ZjM5NDBkOGYtMjAyYS00Y2ZiLThhMzEtZTdjOTYxZGY3M2IzLjM1YTE1MzViLTNkMDctNGQ2My1hZTg1LTY4NmNlOTJlMjE4MHgxNzg5NjAyNTczNzE2MDU1MDAw parts=108462026/09/16 23:49:34 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete8472026/09/16 23:49:34 INFO Completed upload id=18482026/09/16 23:49:34 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000008492026/09/16 23:49:34 INFO Received uploads request method=POST path=/api/pending_closures8502026/09/16 23:49:34 INFO Received uploads request method=POST path=/api/pending_closures8512026/09/16 23:49:34 INFO Starting cleanup of old closures method=DELETE path=/api/closures8522026/09/16 23:49:34 INFO Aborted multipart uploads count=08532026/09/16 23:49:34 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=08542026/09/16 23:49:34 INFO Vacuumed table table=pending_closures8552026/09/16 23:49:34 INFO Vacuumed table table=pending_objects8562026/09/16 23:49:34 INFO Vacuumed table table=multipart_uploads8572026/09/16 23:49:34 INFO Vacuumed table table=closures8582026/09/16 23:49:34 INFO Vacuumed table table=objects8592026/09/16 23:49:34 INFO Received get closure request method=GET path=/api/closures/00000000000000000000000000000000860--- PASS: TestService_createPendingClosureHandler (2.23s)861=== CONT TestClaim_FailWakesWaitersButIsNotRemembered862=== NAME TestClientCADerivations863 client_ca_test.go:136: Built CA derivation: /nix/var/nix/builds/nix-62631-4145625453/TestClientCADerivations1379577879/001/store/0a8zwppw240b4a3lv4dydqrcwn195fwh-ca-test8642026/09/16 23:49:35 INFO Received uploads request method=POST path=/api/pending_closures865 client_ca_test.go:139: Found 1 dependencies (including self)8662026/09/16 23:49:35 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"8672026/09/16 23:49:35 WARN claim: cannot clear write deadline error="feature not supported"868--- PASS: TestClaim_TooManyStreams (2.58s)869=== CONT TestClaim_HolderDisconnectKeepsClaim8702026/09/16 23:49:35 INFO Received uploads request method=POST path=/api/pending_closures8712026/09/16 23:49:35 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)8722026/09/16 23:49:35 INFO Uploading 0a8zwppw240b4a3lv4dydqrcwn195fwh-ca-test (144B)8732026/09/16 23:49:35 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"8742026/09/16 23:49:35 WARN Failed to register uploaded object key=log/bw8ljc3y58y51mp460ipybp2n8wqzbj5-ca-test.drv error="server returned 404: 404 page not found\n"8752026/09/16 23:49:35 WARN Failed to register uploaded object key=0a8zwppw240b4a3lv4dydqrcwn195fwh.ls error="server returned 404: 404 page not found\n"8762026/09/16 23:49:35 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign8772026/09/16 23:49:35 INFO Signed narinfos id=1 count=18782026/09/16 23:49:35 INFO Uploading 1 narinfos8792026/09/16 23:49:35 WARN Failed to register uploaded object key=0a8zwppw240b4a3lv4dydqrcwn195fwh.narinfo error="server returned 404: 404 page not found\n"8802026/09/16 23:49:35 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete8812026/09/16 23:49:35 INFO Completed upload id=18822026/09/16 23:49:35 INFO Upload complete. (219ms)883=== NAME TestClientCADerivations884 client_ca_test.go:180: Narinfo contains CA field: StorePath: /nix/var/nix/builds/nix-62631-4145625453/TestClientCADerivations1379577879/001/store/0a8zwppw240b4a3lv4dydqrcwn195fwh-ca-test885 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst886 Compression: zstd887 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n888 NarSize: 144889 References: 890 Deriver: /nix/var/nix/builds/nix-62631-4145625453/TestClientCADerivations1379577879/001/store/bw8ljc3y58y51mp460ipybp2n8wqzbj5-ca-test.drv891 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n892 client_ca_test.go:185: Checking for realisation files in S3...893 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations894 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache895 client_ca_test.go:258: nix copy output: error: binary cache 's3://bucket8?endpoint=http://localhost:61022®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/nix/var/nix/builds/nix-62631-4145625453/TestClientCADerivations1379577879/001/store'896 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 1897--- PASS: TestClientCADerivations (2.93s)898=== CONT TestService_healthCheckHandler8992026-09-16 23:49:35.781 UTC [63155] ERROR: relation "goose_db_version" does not exist at character 369002026-09-16 23:49:35.781 UTC [63155] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9012026-09-16 23:49:35.796 UTC [63156] ERROR: relation "goose_db_version" does not exist at character 369022026-09-16 23:49:35.796 UTC [63156] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9032026/09/16 23:49:35 INFO Received uploads request method=POST path=/api/pending_closures9042026/09/16 23:49:35 OK 20241026095416_initial_model.sql (70.8ms)9052026/09/16 23:49:35 OK 20241026095416_initial_model.sql (71ms)9062026/09/16 23:49:35 OK 20251210153512_drop_unused_gin_index.sql (17.79ms)9072026/09/16 23:49:35 OK 20251210153512_drop_unused_gin_index.sql (22.55ms)9082026/09/16 23:49:35 OK 20251218171726_add_pins.sql (37.52ms)9092026/09/16 23:49:35 OK 20251218171726_add_pins.sql (15.38ms)9102026/09/16 23:49:35 OK 20260628120000_add_object_size_and_stats.sql (16.59ms)9112026/09/16 23:49:35 OK 20260628120000_add_object_size_and_stats.sql (34.57ms)9122026/09/16 23:49:36 OK 20260905000000_add_claims.sql (36.2ms)9132026/09/16 23:49:36 goose: successfully migrated database to version: 202609050000009142026/09/16 23:49:36 OK 1_commit_pending_closure.sql (9.03ms)9152026/09/16 23:49:36 OK 2_object_stats_trigger.sql (1.71ms)9162026/09/16 23:49:36 goose: up to current file version: 29172026/09/16 23:49:36 OK 20260905000000_add_claims.sql (44.6ms)9182026/09/16 23:49:36 goose: successfully migrated database to version: 202609050000009192026/09/16 23:49:36 OK 1_commit_pending_closure.sql (6.2ms)9202026/09/16 23:49:36 OK 2_object_stats_trigger.sql (638.92µs)9212026/09/16 23:49:36 goose: up to current file version: 29222026/09/16 23:49:36 WARN claim: cannot clear write deadline error="feature not supported"9232026/09/16 23:49:36 WARN claim: cannot clear write deadline error="feature not supported"9242026/09/16 23:49:36 WARN claim: cannot clear write deadline error="feature not supported"9252026/09/16 23:49:36 INFO Received uploads request method=POST path=/api/pending_closures9262026/09/16 23:49:36 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9272026/09/16 23:49:36 INFO Completed multipart upload object_key=nar/0000000000000000000000000000002000000000000000000000.nar.zst upload_id=ZjM5NDBkOGYtMjAyYS00Y2ZiLThhMzEtZTdjOTYxZGY3M2IzLjMyNjg2ZmIyLWRjYzMtNDMyOS1iNzE2LTExMTk3YmI1YTkwY3gxNzg5NjAyNTc0ODU1ODc3MDAw parts=109282026/09/16 23:49:36 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete9292026/09/16 23:49:36 INFO Completed upload id=19302026/09/16 23:49:36 INFO Received uploads request method=POST path=/api/pending_closures9312026/09/16 23:49:36 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9322026/09/16 23:49:36 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=ZjM5NDBkOGYtMjAyYS00Y2ZiLThhMzEtZTdjOTYxZGY3M2IzLjYwOTgxMjUxLTExMDEtNDRlNy05ODcxLTMzMzAxYzEzY2I5OXgxNzg5NjAyNTc1MTA2ODQ3MDAw parts=109332026/09/16 23:49:36 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete9342026/09/16 23:49:36 INFO Completed upload id=19352026/09/16 23:49:36 INFO Received uploads request method=POST path=/api/pending_closures9362026/09/16 23:49:36 WARN claim: cannot clear write deadline error="feature not supported"9372026/09/16 23:49:36 INFO Received uploads request method=POST path=/api/pending_closures9382026/09/16 23:49:36 WARN claim: cannot clear write deadline error="feature not supported"9392026-09-16 23:49:36.499 UTC [63163] ERROR: relation "goose_db_version" does not exist at character 369402026-09-16 23:49:36.499 UTC [63163] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC941--- PASS: TestClaim_StaleHeartbeatStolen (2.32s)942=== CONT TestService_readinessHandler9432026/09/16 23:49:36 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo9442026/09/16 23:49:36 WARN Found objects in DB but missing from S3, will re-upload count=1945--- PASS: TestService_verifyS3Integrity (3.81s)946=== CONT TestReadProxyConditionalGet9472026/09/16 23:49:36 OK 20241026095416_initial_model.sql (189.38ms)9482026/09/16 23:49:36 OK 20251210153512_drop_unused_gin_index.sql (14.26ms)9492026/09/16 23:49:36 OK 20251218171726_add_pins.sql (28.13ms)9502026/09/16 23:49:36 OK 20260628120000_add_object_size_and_stats.sql (26.51ms)9512026/09/16 23:49:36 WARN claim: cannot clear write deadline error="feature not supported"9522026/09/16 23:49:36 OK 20260905000000_add_claims.sql (30.57ms)9532026/09/16 23:49:36 goose: successfully migrated database to version: 202609050000009542026/09/16 23:49:36 WARN claim: cannot clear write deadline error="feature not supported"9552026/09/16 23:49:36 OK 1_commit_pending_closure.sql (15.17ms)956--- PASS: TestClaim_FailWithoutKindReleases (2.53s)957=== CONT TestUploadHandlersRejectInvalidKeys958=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info959=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info960=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal961=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal962=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key963=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key964=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key965=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key966=== CONT TestIsValidUploadKey967=== RUN TestIsValidUploadKey/narinfo968=== PAUSE TestIsValidUploadKey/narinfo969=== RUN TestIsValidUploadKey/nar_zst970=== PAUSE TestIsValidUploadKey/nar_zst971=== RUN TestIsValidUploadKey/nar_xz972=== PAUSE TestIsValidUploadKey/nar_xz973=== RUN TestIsValidUploadKey/nar_plain974=== PAUSE TestIsValidUploadKey/nar_plain975=== RUN TestIsValidUploadKey/listing976=== PAUSE TestIsValidUploadKey/listing977=== RUN TestIsValidUploadKey/build_log978=== PAUSE TestIsValidUploadKey/build_log979=== RUN TestIsValidUploadKey/build_log_home-manager_file980=== PAUSE TestIsValidUploadKey/build_log_home-manager_file981=== RUN TestIsValidUploadKey/build_log_plus_in_name982=== PAUSE TestIsValidUploadKey/build_log_plus_in_name983=== RUN TestIsValidUploadKey/build_log_question_mark984=== PAUSE TestIsValidUploadKey/build_log_question_mark985=== RUN TestIsValidUploadKey/build_log_equals986=== PAUSE TestIsValidUploadKey/build_log_equals987=== RUN TestIsValidUploadKey/realisation988=== PAUSE TestIsValidUploadKey/realisation989=== RUN TestIsValidUploadKey/realisation_plus_in_output990=== PAUSE TestIsValidUploadKey/realisation_plus_in_output991=== RUN TestIsValidUploadKey/nix-cache-info992=== PAUSE TestIsValidUploadKey/nix-cache-info993=== RUN TestIsValidUploadKey/index.html994=== PAUSE TestIsValidUploadKey/index.html995=== RUN TestIsValidUploadKey/narinfo_key,_nar_type996=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type997=== RUN TestIsValidUploadKey/nar_key,_narinfo_type998=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type999=== RUN TestIsValidUploadKey/listing_key,_narinfo_type1000=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type1001=== RUN TestIsValidUploadKey/traversal1002=== PAUSE TestIsValidUploadKey/traversal1003=== RUN TestIsValidUploadKey/traversal_nar1004=== PAUSE TestIsValidUploadKey/traversal_nar1005=== RUN TestIsValidUploadKey/absolute1006=== PAUSE TestIsValidUploadKey/absolute1007=== RUN TestIsValidUploadKey/empty_key1008=== PAUSE TestIsValidUploadKey/empty_key1009=== RUN TestIsValidUploadKey/unknown_type1010=== PAUSE TestIsValidUploadKey/unknown_type1011=== CONT TestProxyWriteTimeout1012=== RUN TestProxyWriteTimeout/narinfo1013=== PAUSE TestProxyWriteTimeout/narinfo1014=== RUN TestProxyWriteTimeout/1_GiB_nar1015=== PAUSE TestProxyWriteTimeout/1_GiB_nar1016=== RUN TestProxyWriteTimeout/10_GiB_nar1017=== PAUSE TestProxyWriteTimeout/10_GiB_nar1018=== RUN TestProxyWriteTimeout/unknown_size1019=== PAUSE TestProxyWriteTimeout/unknown_size1020=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle10212026/09/16 23:49:36 OK 2_object_stats_trigger.sql (10.79ms)10222026/09/16 23:49:36 goose: up to current file version: 21023--- PASS: TestClaim_StreamsThroughServer (3.76s)1024=== CONT TestSkippedUploadsHandler10252026/09/16 23:49:37 INFO Client skipped oversized paths paths=3 nar_bytes=50000000001026--- PASS: TestSkippedUploadsHandler (0.00s)1027=== CONT TestParseSize1028--- PASS: TestParseSize (0.00s)1029=== CONT TestService_Rustfstest10302026/09/16 23:49:37 WARN claim: cannot clear write deadline error="feature not supported"10312026/09/16 23:49:37 WARN claim: cannot clear write deadline error="feature not supported"10322026/09/16 23:49:37 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10332026/09/16 23:49:37 INFO Completed multipart upload object_key=nar/0000000000000000000000000000001700000000000000000000.nar.zst upload_id=ZjM5NDBkOGYtMjAyYS00Y2ZiLThhMzEtZTdjOTYxZGY3M2IzLjEwYjlhOGExLWNjOWMtNDIxOC1hMTE2LWYwMTJjMjhjNzFhMngxNzg5NjAyNTc1ODYzMzM0MDAw parts=1010342026/09/16 23:49:37 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete10352026/09/16 23:49:37 INFO Completed upload id=110362026/09/16 23:49:37 WARN claim: cannot clear write deadline error="feature not supported"10372026-09-16 23:49:37.395 UTC [63176] ERROR: relation "goose_db_version" does not exist at character 3610382026-09-16 23:49:37.395 UTC [63176] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10392026/09/16 23:49:37 INFO Aborted multipart uploads count=010402026/09/16 23:49:37 WARN Force mode enabled - objects will be deleted immediately without grace period10412026/09/16 23:49:37 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=010422026/09/16 23:49:37 WARN claim: cannot clear write deadline error="feature not supported"10432026/09/16 23:49:37 INFO Vacuumed table table=pending_closures10442026/09/16 23:49:37 WARN claim: cannot clear write deadline error="feature not supported"10452026/09/16 23:49:37 WARN claim: cannot clear write deadline error="feature not supported"1046--- PASS: TestClaim_FailWakesWaitersButIsNotRemembered (2.48s)1047=== CONT TestPresignedUploadRegisteredBeforeCommit10482026/09/16 23:49:37 INFO Vacuumed table table=pending_objects10492026/09/16 23:49:37 INFO Vacuumed table table=multipart_uploads10502026/09/16 23:49:37 INFO Vacuumed table table=closures10512026/09/16 23:49:37 INFO Vacuumed table table=objects1052--- PASS: TestClaim_InputsTouched (4.13s)1053=== CONT TestCompletedNarNotReofferedAcrossClosures10542026/09/16 23:49:37 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10552026/09/16 23:49:37 WARN claim: cannot clear write deadline error="feature not supported"10562026/09/16 23:49:37 INFO Completed multipart upload object_key=nar/0000000000000000000000000000001600000000000000000000.nar.zst upload_id=ZjM5NDBkOGYtMjAyYS00Y2ZiLThhMzEtZTdjOTYxZGY3M2IzLmYzOGU4NTI2LTkzMzYtNDdhZS05NWUwLTNjZjMxYTRiNjllM3gxNzg5NjAyNTc2MTU2MTY4MDAw parts=1010572026/09/16 23:49:37 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign10582026/09/16 23:49:37 INFO Signed narinfos id=1 count=110592026/09/16 23:49:37 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete10602026/09/16 23:49:37 OK 20241026095416_initial_model.sql (189.42ms)10612026/09/16 23:49:37 INFO Completed upload id=11062=== NAME TestClaim_TwoInstances1063 claims_test.go:419: status = "build" ({Status:build Token:6 Kind:}), want "built"1064--- FAIL: TestClaim_TwoInstances (3.69s)1065=== CONT TestCompleteMultipartUpload_ErrorButObjectExists10662026-09-16 23:49:37.647 UTC [63185] LOG: could not send data to client: Broken pipe10672026-09-16 23:49:37.647 UTC [63185] FATAL: connection to client lost10682026/09/16 23:49:37 OK 20251210153512_drop_unused_gin_index.sql (17.75ms)10692026/09/16 23:49:37 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10702026/09/16 23:49:37 OK 20251218171726_add_pins.sql (17.68ms)10712026-09-16 23:49:37.691 UTC [63188] ERROR: relation "goose_db_version" does not exist at character 3610722026-09-16 23:49:37.691 UTC [63188] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10732026/09/16 23:49:37 OK 20260628120000_add_object_size_and_stats.sql (27.79ms)1074--- PASS: TestService_healthCheckHandler (2.07s)1075=== CONT TestRedundantMultipartUpload10762026/09/16 23:49:37 OK 20260905000000_add_claims.sql (44.17ms)10772026/09/16 23:49:37 goose: successfully migrated database to version: 2026090500000010782026/09/16 23:49:37 OK 1_commit_pending_closure.sql (7.12ms)10792026/09/16 23:49:37 OK 2_object_stats_trigger.sql (13.19ms)10802026/09/16 23:49:37 goose: up to current file version: 210812026/09/16 23:49:37 OK 20241026095416_initial_model.sql (31.65ms)10822026/09/16 23:49:37 INFO Completed multipart upload object_key=nar/0000000000000000000000000000002100000000000000000000.nar.zst upload_id=ZjM5NDBkOGYtMjAyYS00Y2ZiLThhMzEtZTdjOTYxZGY3M2IzLjQ1MzZiOWRlLWVmYjAtNDg3MC05YjQxLTU3ZjcxNTYzOWFkYXgxNzg5NjAyNTc2MjEyODc1MDAw parts=1010832026/09/16 23:49:37 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete10842026-09-16 23:49:37.784 UTC [63191] ERROR: relation "goose_db_version" does not exist at character 3610852026-09-16 23:49:37.784 UTC [63191] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10862026/09/16 23:49:37 INFO Completed upload id=210872026/09/16 23:49:37 OK 20251210153512_drop_unused_gin_index.sql (3.46ms)1088--- PASS: TestPresent (4.98s)1089=== CONT TestReadRedirectUsesPublicS3URL10902026/09/16 23:49:37 OK 20251218171726_add_pins.sql (4.03ms)10912026/09/16 23:49:37 OK 20260628120000_add_object_size_and_stats.sql (7.04ms)10922026/09/16 23:49:37 OK 20260905000000_add_claims.sql (23.15ms)10932026/09/16 23:49:37 goose: successfully migrated database to version: 2026090500000010942026/09/16 23:49:37 OK 1_commit_pending_closure.sql (5.72ms)10952026/09/16 23:49:37 OK 2_object_stats_trigger.sql (738.33µs)10962026/09/16 23:49:37 goose: up to current file version: 210972026/09/16 23:49:37 OK 20241026095416_initial_model.sql (62.38ms)10982026/09/16 23:49:37 OK 20251210153512_drop_unused_gin_index.sql (1.21ms)10992026/09/16 23:49:37 OK 20251218171726_add_pins.sql (13.84ms)11002026/09/16 23:49:37 OK 20260628120000_add_object_size_and_stats.sql (14.68ms)11012026/09/16 23:49:37 OK 20260905000000_add_claims.sql (37.46ms)11022026/09/16 23:49:37 goose: successfully migrated database to version: 2026090500000011032026/09/16 23:49:37 OK 1_commit_pending_closure.sql (13.11ms)11042026-09-16 23:49:37.934 UTC [63195] ERROR: relation "goose_db_version" does not exist at character 3611052026-09-16 23:49:37.934 UTC [63195] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11062026/09/16 23:49:37 OK 2_object_stats_trigger.sql (9ms)11072026/09/16 23:49:37 goose: up to current file version: 211082026/09/16 23:49:38 OK 20241026095416_initial_model.sql (35.03ms)11092026-09-16 23:49:38.018 UTC [63196] ERROR: relation "goose_db_version" does not exist at character 3611102026-09-16 23:49:38.018 UTC [63196] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11112026/09/16 23:49:38 WARN readiness check failed error="closed pool"1112--- PASS: TestService_readinessHandler (1.51s)1113=== CONT TestReadProxyRangeRequest11142026-09-16 23:49:38.042 UTC [63198] ERROR: relation "goose_db_version" does not exist at character 3611152026-09-16 23:49:38.042 UTC [63198] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11162026/09/16 23:49:38 OK 20251210153512_drop_unused_gin_index.sql (38.79ms)11172026/09/16 23:49:38 OK 20251218171726_add_pins.sql (15.89ms)11182026/09/16 23:49:38 OK 20260628120000_add_object_size_and_stats.sql (8.73ms)11192026/09/16 23:49:38 OK 20260905000000_add_claims.sql (10.06ms)11202026/09/16 23:49:38 goose: successfully migrated database to version: 2026090500000011212026/09/16 23:49:38 OK 1_commit_pending_closure.sql (2.47ms)11222026/09/16 23:49:38 OK 2_object_stats_trigger.sql (638.88µs)11232026/09/16 23:49:38 goose: up to current file version: 211242026/09/16 23:49:38 OK 20241026095416_initial_model.sql (42.68ms)11252026/09/16 23:49:38 OK 20251210153512_drop_unused_gin_index.sql (1.04ms)11262026/09/16 23:49:38 OK 20251218171726_add_pins.sql (13.5ms)11272026/09/16 23:49:38 OK 20241026095416_initial_model.sql (59.2ms)11282026/09/16 23:49:38 OK 20251210153512_drop_unused_gin_index.sql (1.26ms)11292026/09/16 23:49:38 OK 20260628120000_add_object_size_and_stats.sql (14.63ms)11302026/09/16 23:49:38 OK 20251218171726_add_pins.sql (13.38ms)11312026/09/16 23:49:38 OK 20260905000000_add_claims.sql (27.14ms)11322026/09/16 23:49:38 goose: successfully migrated database to version: 2026090500000011332026/09/16 23:49:38 OK 20260628120000_add_object_size_and_stats.sql (20.4ms)11342026/09/16 23:49:38 OK 1_commit_pending_closure.sql (15.1ms)11352026/09/16 23:49:38 OK 2_object_stats_trigger.sql (5.12ms)11362026/09/16 23:49:38 goose: up to current file version: 211372026/09/16 23:49:38 OK 20260905000000_add_claims.sql (17.65ms)11382026/09/16 23:49:38 goose: successfully migrated database to version: 2026090500000011392026-09-16 23:49:38.190 UTC [63200] ERROR: relation "goose_db_version" does not exist at character 3611402026-09-16 23:49:38.190 UTC [63200] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11412026/09/16 23:49:38 OK 1_commit_pending_closure.sql (5.8ms)11422026/09/16 23:49:38 OK 2_object_stats_trigger.sql (1.04ms)11432026/09/16 23:49:38 goose: up to current file version: 211442026/09/16 23:49:38 OK 20241026095416_initial_model.sql (25.41ms)11452026/09/16 23:49:38 OK 20251210153512_drop_unused_gin_index.sql (12.17ms)11462026-09-16 23:49:38.254 UTC [63201] ERROR: relation "goose_db_version" does not exist at character 3611472026-09-16 23:49:38.254 UTC [63201] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11482026-09-16 23:49:38.263 UTC [63202] ERROR: relation "goose_db_version" does not exist at character 3611492026-09-16 23:49:38.263 UTC [63202] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11502026/09/16 23:49:38 OK 20251218171726_add_pins.sql (10.56ms)1151--- PASS: TestReadProxyConditionalGet (1.75s)1152=== CONT TestReadRedirectKeepsNarinfoProxied11532026/09/16 23:49:38 OK 20260628120000_add_object_size_and_stats.sql (19.92ms)11542026/09/16 23:49:38 OK 20260905000000_add_claims.sql (6.02ms)11552026/09/16 23:49:38 goose: successfully migrated database to version: 2026090500000011562026/09/16 23:49:38 OK 1_commit_pending_closure.sql (8.35ms)11572026/09/16 23:49:38 OK 2_object_stats_trigger.sql (649µs)11582026/09/16 23:49:38 goose: up to current file version: 211592026/09/16 23:49:38 OK 20241026095416_initial_model.sql (34.39ms)11602026/09/16 23:49:38 OK 20251210153512_drop_unused_gin_index.sql (1.06ms)11612026/09/16 23:49:38 OK 20241026095416_initial_model.sql (37.15ms)11622026/09/16 23:49:38 OK 20251218171726_add_pins.sql (8.91ms)11632026/09/16 23:49:38 OK 20251210153512_drop_unused_gin_index.sql (974.21µs)11642026/09/16 23:49:38 OK 20251218171726_add_pins.sql (5.65ms)11652026/09/16 23:49:38 OK 20260628120000_add_object_size_and_stats.sql (16.56ms)11662026/09/16 23:49:38 OK 20260628120000_add_object_size_and_stats.sql (10.82ms)11672026/09/16 23:49:38 OK 20260905000000_add_claims.sql (16.39ms)11682026/09/16 23:49:38 goose: successfully migrated database to version: 2026090500000011692026/09/16 23:49:38 OK 20260905000000_add_claims.sql (21.74ms)11702026/09/16 23:49:38 goose: successfully migrated database to version: 2026090500000011712026/09/16 23:49:38 OK 1_commit_pending_closure.sql (7.14ms)11722026/09/16 23:49:38 OK 2_object_stats_trigger.sql (635.5µs)11732026/09/16 23:49:38 goose: up to current file version: 211742026/09/16 23:49:38 OK 1_commit_pending_closure.sql (5.8ms)11752026/09/16 23:49:38 OK 2_object_stats_trigger.sql (612.63µs)11762026/09/16 23:49:38 goose: up to current file version: 211772026/09/16 23:49:38 INFO Received uploads request method=POST path=/api/pending_closures11782026-09-16 23:49:38.465 UTC [63205] ERROR: relation "goose_db_version" does not exist at character 3611792026-09-16 23:49:38.465 UTC [63205] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11802026/09/16 23:49:38 OK 20241026095416_initial_model.sql (64.46ms)11812026/09/16 23:49:38 OK 20251210153512_drop_unused_gin_index.sql (5.66ms)11822026/09/16 23:49:38 OK 20251218171726_add_pins.sql (9.46ms)11832026/09/16 23:49:38 OK 20260628120000_add_object_size_and_stats.sql (18.39ms)11842026/09/16 23:49:38 OK 20260905000000_add_claims.sql (23.98ms)11852026/09/16 23:49:38 goose: successfully migrated database to version: 2026090500000011862026-09-16 23:49:38.629 UTC [63206] ERROR: relation "goose_db_version" does not exist at character 3611872026-09-16 23:49:38.629 UTC [63206] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11882026/09/16 23:49:38 OK 1_commit_pending_closure.sql (5.43ms)11892026/09/16 23:49:38 OK 2_object_stats_trigger.sql (584.67µs)11902026/09/16 23:49:38 goose: up to current file version: 21191--- PASS: TestService_Rustfstest (1.57s)1192=== CONT TestReadRedirectNar11932026/09/16 23:49:38 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11942026/09/16 23:49:38 OK 20241026095416_initial_model.sql (20.5ms)11952026/09/16 23:49:38 OK 20251210153512_drop_unused_gin_index.sql (14.46ms)11962026/09/16 23:49:38 OK 20251218171726_add_pins.sql (21.77ms)11972026/09/16 23:49:38 OK 20260628120000_add_object_size_and_stats.sql (15.67ms)11982026/09/16 23:49:38 OK 20260905000000_add_claims.sql (16.22ms)11992026/09/16 23:49:38 goose: successfully migrated database to version: 2026090500000012002026/09/16 23:49:38 OK 1_commit_pending_closure.sql (13.19ms)12012026/09/16 23:49:38 OK 2_object_stats_trigger.sql (9.13ms)12022026/09/16 23:49:38 goose: up to current file version: 212032026-09-16 23:49:38.854 UTC [63209] ERROR: relation "goose_db_version" does not exist at character 3612042026-09-16 23:49:38.854 UTC [63209] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12052026/09/16 23:49:38 INFO Received uploads request method=POST path=/api/pending_closures12062026/09/16 23:49:38 OK 20241026095416_initial_model.sql (36.07ms)12072026/09/16 23:49:38 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst12082026/09/16 23:49:38 INFO Received uploads request method=POST path=/api/pending_closures1209--- PASS: TestPresignedUploadRegisteredBeforeCommit (1.50s)1210=== CONT TestReadProxyDisabled12112026/09/16 23:49:38 OK 20251210153512_drop_unused_gin_index.sql (10.97ms)12122026/09/16 23:49:38 OK 20251218171726_add_pins.sql (11.2ms)12132026/09/16 23:49:38 OK 20260628120000_add_object_size_and_stats.sql (13.04ms)12142026/09/16 23:49:38 OK 20260905000000_add_claims.sql (25.36ms)12152026/09/16 23:49:38 goose: successfully migrated database to version: 2026090500000012162026/09/16 23:49:38 OK 1_commit_pending_closure.sql (10.66ms)12172026/09/16 23:49:39 OK 2_object_stats_trigger.sql (5.48ms)12182026/09/16 23:49:39 goose: up to current file version: 212192026/09/16 23:49:39 INFO Received uploads request method=POST path=/api/pending_closures12202026/09/16 23:49:39 INFO Received uploads request method=POST path=/api/pending_closures12212026-09-16 23:49:39.396 UTC [63215] ERROR: relation "goose_db_version" does not exist at character 3612222026-09-16 23:49:39.396 UTC [63215] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12232026/09/16 23:49:39 OK 20241026095416_initial_model.sql (126.84ms)12242026/09/16 23:49:39 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12252026/09/16 23:49:39 OK 20251210153512_drop_unused_gin_index.sql (13.96ms)12262026/09/16 23:49:39 OK 20251218171726_add_pins.sql (17.96ms)12272026/09/16 23:49:39 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=ZjM5NDBkOGYtMjAyYS00Y2ZiLThhMzEtZTdjOTYxZGY3M2IzLjYzZTljZDExLWY0ZGMtNDg3Yy04OWE5LTU0ZDE5NDAxZGI3M3gxNzg5NjAyNTc5MzYxOTkyMDAw12282026/09/16 23:49:39 OK 20260628120000_add_object_size_and_stats.sql (20.92ms)1229--- PASS: TestClaim_HolderDisconnectKeepsClaim (4.32s)1230=== CONT TestReadProxyRootRedirectsToIndexHTML12312026/09/16 23:49:39 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=ZjM5NDBkOGYtMjAyYS00Y2ZiLThhMzEtZTdjOTYxZGY3M2IzLjYzZTljZDExLWY0ZGMtNDg3Yy04OWE5LTU0ZDE5NDAxZGI3M3gxNzg5NjAyNTc5MzYxOTkyMDAw parts=11232--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (1.99s)1233=== CONT TestGracefulShutdownDrainsInflight12342026/09/16 23:49:39 OK 20260905000000_add_claims.sql (24.97ms)12352026/09/16 23:49:39 goose: successfully migrated database to version: 2026090500000012362026/09/16 23:49:39 INFO Starting HTTP server address=127.0.0.1:6112412372026/09/16 23:49:39 INFO Shutdown signal received, draining in-flight requests timeout=10s12382026/09/16 23:49:39 OK 1_commit_pending_closure.sql (9.98ms)12392026/09/16 23:49:39 OK 2_object_stats_trigger.sql (11.22ms)12402026/09/16 23:49:39 goose: up to current file version: 21241--- PASS: TestReadRedirectUsesPublicS3URL (1.89s)1242=== CONT TestPinProtectsFromGC1243--- PASS: TestGracefulShutdownDrainsInflight (0.08s)1244=== CONT TestGCTaskStore_StartNew1245--- PASS: TestGCTaskStore_StartNew (0.00s)1246=== CONT TestGCMetrics12472026/09/16 23:49:39 INFO Received uploads request method=POST path=/api/pending_closures12482026/09/16 23:49:39 INFO Received uploads request method=POST path=/api/pending_closures1249--- PASS: TestReadProxyRangeRequest (2.15s)1250=== CONT TestGCBugBareHashReferences12512026-09-16 23:49:40.460 UTC [63235] ERROR: relation "goose_db_version" does not exist at character 3612522026-09-16 23:49:40.460 UTC [63235] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12532026-09-16 23:49:40.461 UTC [63234] ERROR: relation "goose_db_version" does not exist at character 3612542026-09-16 23:49:40.461 UTC [63234] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1255--- PASS: TestReadRedirectKeepsNarinfoProxied (2.24s)1256=== CONT TestResolveDBConnectionString1257=== RUN TestResolveDBConnectionString/flag_wins1258=== PAUSE TestResolveDBConnectionString/flag_wins1259=== RUN TestResolveDBConnectionString/file_when_flag_empty1260=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1261=== RUN TestResolveDBConnectionString/missing_file_is_an_error1262=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1263=== RUN TestResolveDBConnectionString/PGHOST_allows_empty1264=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1265=== RUN TestResolveDBConnectionString/nothing_configured1266=== PAUSE TestResolveDBConnectionString/nothing_configured1267=== CONT TestGCTaskStore_Fail1268--- PASS: TestGCTaskStore_Fail (0.00s)1269=== CONT TestClientIntegration12702026/09/16 23:49:40 OK 20241026095416_initial_model.sql (78.21ms)12712026/09/16 23:49:40 OK 20251210153512_drop_unused_gin_index.sql (24.86ms)12722026/09/16 23:49:40 OK 20241026095416_initial_model.sql (104.26ms)12732026-09-16 23:49:40.615 UTC [63240] ERROR: relation "goose_db_version" does not exist at character 3612742026-09-16 23:49:40.615 UTC [63240] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12752026/09/16 23:49:40 OK 20251210153512_drop_unused_gin_index.sql (16.24ms)12762026/09/16 23:49:40 OK 20251218171726_add_pins.sql (17.66ms)12772026/09/16 23:49:40 OK 20251218171726_add_pins.sql (26.77ms)12782026/09/16 23:49:40 OK 20260628120000_add_object_size_and_stats.sql (29.87ms)12792026/09/16 23:49:40 OK 20260905000000_add_claims.sql (12.78ms)12802026/09/16 23:49:40 goose: successfully migrated database to version: 2026090500000012812026/09/16 23:49:40 OK 20260628120000_add_object_size_and_stats.sql (26.45ms)12822026/09/16 23:49:40 OK 1_commit_pending_closure.sql (11.32ms)12832026/09/16 23:49:40 OK 2_object_stats_trigger.sql (689.71µs)12842026/09/16 23:49:40 goose: up to current file version: 212852026/09/16 23:49:40 OK 20260905000000_add_claims.sql (81.22ms)12862026/09/16 23:49:40 goose: successfully migrated database to version: 2026090500000012872026/09/16 23:49:40 OK 1_commit_pending_closure.sql (5.13ms)12882026/09/16 23:49:40 OK 2_object_stats_trigger.sql (587.42µs)12892026/09/16 23:49:40 goose: up to current file version: 212902026/09/16 23:49:40 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12912026/09/16 23:49:40 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=ZjM5NDBkOGYtMjAyYS00Y2ZiLThhMzEtZTdjOTYxZGY3M2IzLjc1NWE0NDNhLTE5OGUtNDllOS04MjZhLTJiOWFmNTdmOTkzZXgxNzg5NjAyNTc5MTEzMTEzMDAw parts=1212922026/09/16 23:49:40 INFO Received uploads request method=POST path=/api/pending_closures1293--- PASS: TestCompletedNarNotReofferedAcrossClosures (3.31s)1294=== CONT TestClientWithDependencies1295--- PASS: TestReadRedirectNar (2.23s)1296=== CONT TestClientMultipleUploads12972026/09/16 23:49:40 OK 20241026095416_initial_model.sql (231.91ms)12982026/09/16 23:49:40 OK 20251210153512_drop_unused_gin_index.sql (5.73ms)12992026/09/16 23:49:40 OK 20251218171726_add_pins.sql (12.73ms)13002026/09/16 23:49:40 OK 20260628120000_add_object_size_and_stats.sql (27.88ms)13012026/09/16 23:49:40 OK 20260905000000_add_claims.sql (37.82ms)13022026/09/16 23:49:40 goose: successfully migrated database to version: 2026090500000013032026/09/16 23:49:40 OK 1_commit_pending_closure.sql (6.78ms)13042026/09/16 23:49:40 OK 2_object_stats_trigger.sql (646.17µs)13052026/09/16 23:49:40 goose: up to current file version: 21306--- PASS: TestReadProxyDisabled (2.18s)1307=== CONT TestService_ReadScope_PublicByDefault13082026-09-16 23:49:41.140 UTC [63252] ERROR: relation "goose_db_version" does not exist at character 3613092026-09-16 23:49:41.140 UTC [63252] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13102026/09/16 23:49:41 OK 20241026095416_initial_model.sql (168.13ms)13112026/09/16 23:49:41 OK 20251210153512_drop_unused_gin_index.sql (7.64ms)13122026/09/16 23:49:41 OK 20251218171726_add_pins.sql (27.88ms)13132026/09/16 23:49:41 OK 20260628120000_add_object_size_and_stats.sql (30.6ms)1314--- PASS: TestReadProxyRootRedirectsToIndexHTML (1.79s)1315=== CONT TestClaim_GCMarkedOutputCountsAsAbsent13162026/09/16 23:49:41 OK 20260905000000_add_claims.sql (58.02ms)13172026/09/16 23:49:41 goose: successfully migrated database to version: 2026090500000013182026/09/16 23:49:41 OK 1_commit_pending_closure.sql (1.7ms)13192026/09/16 23:49:41 OK 2_object_stats_trigger.sql (295.67µs)13202026/09/16 23:49:41 goose: up to current file version: 213212026-09-16 23:49:41.556 UTC [63260] ERROR: relation "goose_db_version" does not exist at character 3613222026-09-16 23:49:41.556 UTC [63260] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13232026/09/16 23:49:41 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13242026/09/16 23:49:41 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=ZjM5NDBkOGYtMjAyYS00Y2ZiLThhMzEtZTdjOTYxZGY3M2IzLjMyYmMxM2NkLTE0MDktNDhjNy1iNDdlLWVjYWE0Y2VkYmNiYXgxNzg5NjAyNTc5ODY5OTAxMDAw parts=121325--- PASS: TestRedundantMultipartUpload (4.06s)1326=== CONT TestClaim_BuildWaitComplete13272026/09/16 23:49:41 OK 20241026095416_initial_model.sql (212.88ms)13282026/09/16 23:49:41 OK 20251210153512_drop_unused_gin_index.sql (16.57ms)13292026/09/16 23:49:41 OK 20251218171726_add_pins.sql (24.96ms)13302026/09/16 23:49:41 OK 20260628120000_add_object_size_and_stats.sql (15.96ms)13312026/09/16 23:49:41 OK 20260905000000_add_claims.sql (28.16ms)13322026/09/16 23:49:41 goose: successfully migrated database to version: 2026090500000013332026-09-16 23:49:41.943 UTC [63267] ERROR: relation "goose_db_version" does not exist at character 3613342026-09-16 23:49:41.943 UTC [63267] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13352026/09/16 23:49:41 OK 1_commit_pending_closure.sql (25.8ms)13362026/09/16 23:49:41 OK 2_object_stats_trigger.sql (6.03ms)13372026/09/16 23:49:41 goose: up to current file version: 213382026-09-16 23:49:41.987 UTC [63268] ERROR: relation "goose_db_version" does not exist at character 3613392026-09-16 23:49:41.987 UTC [63268] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13402026-09-16 23:49:42.023 UTC [63271] ERROR: relation "goose_db_version" does not exist at character 3613412026-09-16 23:49:42.023 UTC [63271] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13422026/09/16 23:49:42 OK 20241026095416_initial_model.sql (40.83ms)13432026/09/16 23:49:42 OK 20251210153512_drop_unused_gin_index.sql (10.66ms)13442026/09/16 23:49:42 OK 20251218171726_add_pins.sql (18.46ms)13452026/09/16 23:49:42 OK 20260628120000_add_object_size_and_stats.sql (8.28ms)13462026/09/16 23:49:42 OK 20260905000000_add_claims.sql (2.84ms)13472026/09/16 23:49:42 goose: successfully migrated database to version: 2026090500000013482026/09/16 23:49:42 INFO Aborted multipart uploads count=01349=== NAME TestPinProtectsFromGC1350 client_integration_test.go:667: Pinned store path: /nix/var/nix/builds/nix-62631-4145625453/TestPinProtectsFromGC3326031403/001/store/nh7kwyk0678iafywng42ycixa08hqwmr-pinned-file.txt1351 client_integration_test.go:668: Unpinned store path: /nix/var/nix/builds/nix-62631-4145625453/TestPinProtectsFromGC3326031403/001/store/g7hz4z4kymdd3j3wxlnrzvhl1gzqqgwh-unpinned-file.txt13522026/09/16 23:49:42 OK 1_commit_pending_closure.sql (2.59ms)13532026/09/16 23:49:42 OK 2_object_stats_trigger.sql (671.67µs)13542026/09/16 23:49:42 goose: up to current file version: 213552026/09/16 23:49:42 OK 20241026095416_initial_model.sql (38.46ms)13562026/09/16 23:49:42 WARN Force mode enabled - objects will be deleted immediately without grace period13572026/09/16 23:49:42 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=013582026/09/16 23:49:42 INFO Vacuumed table table=pending_closures13592026/09/16 23:49:42 INFO Vacuumed table table=pending_objects13602026/09/16 23:49:42 INFO Vacuumed table table=multipart_uploads13612026/09/16 23:49:42 OK 20241026095416_initial_model.sql (24.25ms)13622026/09/16 23:49:42 INFO Vacuumed table table=closures13632026/09/16 23:49:42 OK 20251210153512_drop_unused_gin_index.sql (5.02ms)13642026/09/16 23:49:42 INFO Vacuumed table table=objects1365--- PASS: TestGCMetrics (2.37s)1366=== CONT TestCacheStatsHandler13672026/09/16 23:49:42 OK 20251210153512_drop_unused_gin_index.sql (9.24ms)13682026/09/16 23:49:42 OK 20251218171726_add_pins.sql (15.66ms)13692026/09/16 23:49:42 OK 20251218171726_add_pins.sql (7.48ms)13702026/09/16 23:49:42 OK 20260628120000_add_object_size_and_stats.sql (3.72ms)13712026/09/16 23:49:42 OK 20260628120000_add_object_size_and_stats.sql (10.31ms)13722026/09/16 23:49:42 OK 20260905000000_add_claims.sql (16.83ms)13732026/09/16 23:49:42 goose: successfully migrated database to version: 2026090500000013742026/09/16 23:49:42 OK 1_commit_pending_closure.sql (9.15ms)13752026/09/16 23:49:42 OK 2_object_stats_trigger.sql (607.88µs)13762026/09/16 23:49:42 goose: up to current file version: 213772026/09/16 23:49:42 OK 20260905000000_add_claims.sql (24.79ms)13782026/09/16 23:49:42 goose: successfully migrated database to version: 2026090500000013792026/09/16 23:49:42 OK 1_commit_pending_closure.sql (2.11ms)13802026/09/16 23:49:42 OK 2_object_stats_trigger.sql (588.42µs)13812026/09/16 23:49:42 goose: up to current file version: 213822026/09/16 23:49:42 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"13832026-09-16 23:49:42.250 UTC [63286] ERROR: relation "goose_db_version" does not exist at character 3613842026-09-16 23:49:42.250 UTC [63286] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13852026/09/16 23:49:42 INFO Received uploads request method=POST path=/api/pending_closures13862026/09/16 23:49:42 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)13872026/09/16 23:49:42 INFO Uploading nh7kwyk0678iafywng42ycixa08hqwmr-pinned-file.txt (128B)13882026/09/16 23:49:42 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"13892026/09/16 23:49:42 WARN Failed to register uploaded object key=nh7kwyk0678iafywng42ycixa08hqwmr.ls error="server returned 404: 404 page not found\n"13902026/09/16 23:49:42 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign13912026/09/16 23:49:42 INFO Signed narinfos id=1 count=113922026/09/16 23:49:42 INFO Uploading 1 narinfos13932026/09/16 23:49:42 WARN Failed to register uploaded object key=nh7kwyk0678iafywng42ycixa08hqwmr.narinfo error="server returned 404: 404 page not found\n"13942026/09/16 23:49:42 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete13952026/09/16 23:49:42 OK 20241026095416_initial_model.sql (29.01ms)13962026/09/16 23:49:42 INFO Completed upload id=113972026/09/16 23:49:42 INFO Upload complete. (179ms)13982026/09/16 23:49:42 OK 20251210153512_drop_unused_gin_index.sql (7.01ms)13992026/09/16 23:49:42 OK 20251218171726_add_pins.sql (6.24ms)14002026/09/16 23:49:42 OK 20260628120000_add_object_size_and_stats.sql (17.54ms)14012026/09/16 23:49:42 OK 20260905000000_add_claims.sql (11.54ms)14022026/09/16 23:49:42 goose: successfully migrated database to version: 2026090500000014032026/09/16 23:49:42 OK 1_commit_pending_closure.sql (6.75ms)14042026/09/16 23:49:42 OK 2_object_stats_trigger.sql (627µs)14052026/09/16 23:49:42 goose: up to current file version: 214062026/09/16 23:49:42 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"14072026-09-16 23:49:42.410 UTC [63295] ERROR: relation "goose_db_version" does not exist at character 3614082026-09-16 23:49:42.410 UTC [63295] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1409--- PASS: TestGCBugBareHashReferences (2.29s)1410=== CONT TestCacheConfigHandler1411=== RUN TestCacheConfigHandler/full_config,_no_issuer1412=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1413=== RUN TestCacheConfigHandler/no_cache_url_configured1414=== PAUSE TestCacheConfigHandler/no_cache_url_configured1415=== RUN TestCacheConfigHandler/no_signing_keys1416=== PAUSE TestCacheConfigHandler/no_signing_keys1417=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1418=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1419=== CONT TestService_ReadAuthMiddleware14202026/09/16 23:49:42 OK 20241026095416_initial_model.sql (29.57ms)14212026/09/16 23:49:42 OK 20251210153512_drop_unused_gin_index.sql (7.98ms)14222026/09/16 23:49:42 INFO Received uploads request method=POST path=/api/pending_closures14232026/09/16 23:49:42 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)14242026/09/16 23:49:42 INFO Uploading g7hz4z4kymdd3j3wxlnrzvhl1gzqqgwh-unpinned-file.txt (128B)14252026/09/16 23:49:42 OK 20251218171726_add_pins.sql (9.13ms)14262026/09/16 23:49:42 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"1427=== NAME TestClientIntegration1428 client_integration_test.go:286: Created store path: /nix/var/nix/builds/nix-62631-4145625453/TestClientIntegration929513276/002/store/0276zsmbxq643x572lncdlmwk4ny6pm3-test-file.txt14292026/09/16 23:49:42 WARN Failed to register uploaded object key=g7hz4z4kymdd3j3wxlnrzvhl1gzqqgwh.ls error="server returned 404: 404 page not found\n"14302026/09/16 23:49:42 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign14312026/09/16 23:49:42 INFO Signed narinfos id=2 count=114322026/09/16 23:49:42 INFO Uploading 1 narinfos14332026/09/16 23:49:42 OK 20260628120000_add_object_size_and_stats.sql (16.62ms)14342026/09/16 23:49:42 WARN Failed to register uploaded object key=g7hz4z4kymdd3j3wxlnrzvhl1gzqqgwh.narinfo error="server returned 404: 404 page not found\n"14352026/09/16 23:49:42 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete14362026/09/16 23:49:42 INFO Completed upload id=214372026/09/16 23:49:42 INFO Upload complete. (141ms)14382026/09/16 23:49:42 OK 20260905000000_add_claims.sql (12.33ms)14392026/09/16 23:49:42 goose: successfully migrated database to version: 2026090500000014402026/09/16 23:49:42 OK 1_commit_pending_closure.sql (1.19ms)14412026/09/16 23:49:42 OK 2_object_stats_trigger.sql (573.29µs)14422026/09/16 23:49:42 goose: up to current file version: 214432026/09/16 23:49:42 INFO Received create pin request method=POST path=/api/pins/myapp14442026/09/16 23:49:42 INFO Created/updated pin name=myapp store_path=/nix/var/nix/builds/nix-62631-4145625453/TestPinProtectsFromGC3326031403/001/store/nh7kwyk0678iafywng42ycixa08hqwmr-pinned-file.txt narinfo_key=nh7kwyk0678iafywng42ycixa08hqwmr.narinfo14452026-09-16 23:49:42.555 UTC [63309] ERROR: relation "goose_db_version" does not exist at character 3614462026-09-16 23:49:42.555 UTC [63309] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14472026/09/16 23:49:42 INFO Starting cleanup of old closures method=DELETE path=/api/closures14482026/09/16 23:49:42 INFO Garbage collection started14492026/09/16 23:49:42 INFO Aborted multipart uploads count=014502026/09/16 23:49:42 WARN Force mode enabled - objects will be deleted immediately without grace period14512026/09/16 23:49:42 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"14522026/09/16 23:49:42 OK 20241026095416_initial_model.sql (34.48ms)14532026/09/16 23:49:42 OK 20251210153512_drop_unused_gin_index.sql (5.98ms)14542026/09/16 23:49:42 OK 20251218171726_add_pins.sql (13.81ms)14552026/09/16 23:49:42 OK 20260628120000_add_object_size_and_stats.sql (16.13ms)14562026/09/16 23:49:42 OK 20260905000000_add_claims.sql (12.75ms)14572026/09/16 23:49:42 goose: successfully migrated database to version: 2026090500000014582026/09/16 23:49:42 INFO Received uploads request method=POST path=/api/pending_closures14592026/09/16 23:49:42 OK 1_commit_pending_closure.sql (7.96ms)14602026/09/16 23:49:42 OK 2_object_stats_trigger.sql (444.83µs)14612026/09/16 23:49:42 goose: up to current file version: 214622026/09/16 23:49:42 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)14632026/09/16 23:49:42 INFO Uploading 0276zsmbxq643x572lncdlmwk4ny6pm3-test-file.txt (152B)14642026/09/16 23:49:42 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"14652026/09/16 23:49:42 WARN Failed to register uploaded object key=0276zsmbxq643x572lncdlmwk4ny6pm3.ls error="server returned 404: 404 page not found\n"14662026/09/16 23:49:42 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign14672026/09/16 23:49:42 INFO Signed narinfos id=1 count=114682026/09/16 23:49:42 INFO Uploading 1 narinfos14692026/09/16 23:49:42 WARN Failed to register uploaded object key=0276zsmbxq643x572lncdlmwk4ny6pm3.narinfo error="server returned 404: 404 page not found\n"14702026/09/16 23:49:42 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete14712026/09/16 23:49:42 INFO Completed upload id=114722026/09/16 23:49:42 INFO Upload complete. (170ms)14732026/09/16 23:49:42 INFO All 1 paths already cached1474 client_integration_test.go:312: Retrieved narinfo from S3:1475 StorePath: /nix/var/nix/builds/nix-62631-4145625453/TestClientIntegration929513276/002/store/0276zsmbxq643x572lncdlmwk4ny6pm3-test-file.txt1476 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1477 Compression: zstd1478 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11479 NarSize: 1521480 References: 1481 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11482 client_integration_test.go:313: Retrieved .ls file from S3 (compressed size: 77 bytes)1483 client_integration_test.go:313: Decompressed .ls content (64 bytes):1484 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1485 client_integration_test.go:316: Testing garbage collection...1486=== NAME TestClientMultipleUploads1487 client_integration_test.go:358: Created store path 0: /nix/var/nix/builds/nix-62631-4145625453/TestClientMultipleUploads1354926060/001/store/dd98n8sb9ma6jn7hri1slccxh4jrqd0i-test-file-0.txt14882026/09/16 23:49:42 INFO Starting cleanup of old closures method=DELETE path=/api/closures14892026/09/16 23:49:42 INFO Garbage collection started14902026/09/16 23:49:42 INFO Aborted multipart uploads count=014912026/09/16 23:49:42 WARN Force mode enabled - objects will be deleted immediately without grace period1492--- PASS: TestService_ReadScope_PublicByDefault (1.70s)1493=== CONT TestService_RequireScope_OIDC14942026/09/16 23:49:42 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:61192/oidc14952026/09/16 23:49:42 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=014962026/09/16 23:49:42 INFO Vacuumed table table=pending_closures1497=== NAME TestClientMultipleUploads1498 client_integration_test.go:358: Created store path 1: /nix/var/nix/builds/nix-62631-4145625453/TestClientMultipleUploads1354926060/001/store/vql892s34r7lrpckxxnk5afkqa7ax6z9-test-file-1.txt1499=== NAME TestClientWithDependencies1500 client_integration_test.go:613: Built derivation: /nix/var/nix/builds/nix-62631-4145625453/TestClientWithDependencies3720156966/001/store/abbb3xaa1pv5077cnvkvps0n11zx4qgi-test-script15012026/09/16 23:49:42 INFO Vacuumed table table=pending_objects15022026/09/16 23:49:42 INFO Vacuumed table table=multipart_uploads15032026-09-16 23:49:42.864 UTC [63331] ERROR: relation "goose_db_version" does not exist at character 3615042026-09-16 23:49:42.864 UTC [63331] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15052026/09/16 23:49:42 INFO Vacuumed table table=closures15062026/09/16 23:49:42 INFO Vacuumed table table=objects1507 client_integration_test.go:615: Found 1 dependencies (including self)1508=== NAME TestClientMultipleUploads1509 client_integration_test.go:358: Created store path 2: /nix/var/nix/builds/nix-62631-4145625453/TestClientMultipleUploads1354926060/001/store/qncy08g8dqgbl8p3kd0h5n8p5gw5xszc-test-file-2.txt15102026/09/16 23:49:42 OK 20241026095416_initial_model.sql (81.94ms)15112026/09/16 23:49:42 OK 20251210153512_drop_unused_gin_index.sql (6.44ms)15122026/09/16 23:49:42 INFO Received uploads request method=POST path=/api/pending_closures15132026/09/16 23:49:42 OK 20251218171726_add_pins.sql (1.52ms)15142026/09/16 23:49:42 OK 20260628120000_add_object_size_and_stats.sql (2.36ms)15152026/09/16 23:49:42 OK 20260905000000_add_claims.sql (6.72ms)15162026/09/16 23:49:42 goose: successfully migrated database to version: 2026090500000015172026/09/16 23:49:42 OK 1_commit_pending_closure.sql (5.09ms)15182026/09/16 23:49:42 OK 2_object_stats_trigger.sql (326.92µs)15192026/09/16 23:49:42 goose: up to current file version: 215202026/09/16 23:49:43 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"15212026/09/16 23:49:43 INFO Received uploads request method=POST path=/api/pending_closures15222026/09/16 23:49:43 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15232026/09/16 23:49:43 INFO Uploading abbb3xaa1pv5077cnvkvps0n11zx4qgi-test-script (136B)15242026/09/16 23:49:43 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"15252026/09/16 23:49:43 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"15262026/09/16 23:49:43 WARN Failed to register uploaded object key=log/kq0nk2pyg28a47j0117ajiimcgf609ix-test-script.drv error="server returned 404: 404 page not found\n"15272026/09/16 23:49:43 WARN Failed to register uploaded object key=abbb3xaa1pv5077cnvkvps0n11zx4qgi.ls error="server returned 404: 404 page not found\n"15282026/09/16 23:49:43 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign15292026/09/16 23:49:43 INFO Signed narinfos id=1 count=115302026/09/16 23:49:43 INFO Uploading 1 narinfos15312026/09/16 23:49:43 WARN Failed to register uploaded object key=abbb3xaa1pv5077cnvkvps0n11zx4qgi.narinfo error="server returned 404: 404 page not found\n"15322026/09/16 23:49:43 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete15332026/09/16 23:49:43 INFO Completed upload id=115342026/09/16 23:49:43 INFO Upload complete. (116ms)1535=== NAME TestClientWithDependencies1536 client_integration_test.go:617: Skipping nix copy test - isolated store (/nix/var/nix/builds/nix-62631-4145625453/TestClientWithDependencies3720156966/001/store) requires matching store prefix1537--- PASS: TestClientWithDependencies (2.25s)1538=== CONT TestService_AuthMiddleware_OIDC15392026/09/16 23:49:43 INFO Received uploads request method=POST path=/api/pending_closures15402026/09/16 23:49:43 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:61206/oidc15412026/09/16 23:49:43 INFO Received uploads request method=POST path=/api/pending_closures15422026/09/16 23:49:43 WARN claim: cannot clear write deadline error="feature not supported"15432026/09/16 23:49:43 INFO Received uploads request method=POST path=/api/pending_closures15442026/09/16 23:49:43 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)15452026/09/16 23:49:43 INFO Uploading qncy08g8dqgbl8p3kd0h5n8p5gw5xszc-test-file-2.txt (160B)15462026/09/16 23:49:43 INFO Uploading dd98n8sb9ma6jn7hri1slccxh4jrqd0i-test-file-0.txt (160B)15472026/09/16 23:49:43 INFO Uploading vql892s34r7lrpckxxnk5afkqa7ax6z9-test-file-1.txt (160B)15482026/09/16 23:49:43 WARN claim: cannot clear write deadline error="feature not supported"15492026/09/16 23:49:43 WARN claim: cannot clear write deadline error="feature not supported"15502026/09/16 23:49:43 INFO Received uploads request method=POST path=/api/pending_closures15512026/09/16 23:49:43 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=3 objects-deleted-after-grace-period=3003 objects-failed-to-delete=015522026/09/16 23:49:43 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"15532026/09/16 23:49:43 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"15542026/09/16 23:49:43 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"15552026/09/16 23:49:43 WARN Failed to register uploaded object key=qncy08g8dqgbl8p3kd0h5n8p5gw5xszc.ls error="server returned 404: 404 page not found\n"15562026/09/16 23:49:43 INFO Vacuumed table table=pending_closures15572026/09/16 23:49:43 WARN Failed to register uploaded object key=dd98n8sb9ma6jn7hri1slccxh4jrqd0i.ls error="server returned 404: 404 page not found\n"15582026/09/16 23:49:43 WARN Failed to register uploaded object key=vql892s34r7lrpckxxnk5afkqa7ax6z9.ls error="server returned 404: 404 page not found\n"15592026/09/16 23:49:43 INFO Received sign narinfos request method=POST path=/api/pending_closures/3/sign15602026/09/16 23:49:43 INFO Vacuumed table table=pending_objects15612026/09/16 23:49:43 INFO Signed narinfos id=3 count=115622026/09/16 23:49:43 INFO Vacuumed table table=multipart_uploads15632026/09/16 23:49:43 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign15642026/09/16 23:49:43 INFO Signed narinfos id=1 count=115652026/09/16 23:49:43 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign15662026/09/16 23:49:43 INFO Signed narinfos id=2 count=115672026/09/16 23:49:43 INFO Uploading 3 narinfos15682026/09/16 23:49:43 WARN Failed to register uploaded object key=qncy08g8dqgbl8p3kd0h5n8p5gw5xszc.narinfo error="server returned 404: 404 page not found\n"15692026/09/16 23:49:43 WARN Failed to register uploaded object key=vql892s34r7lrpckxxnk5afkqa7ax6z9.narinfo error="server returned 404: 404 page not found\n"15702026/09/16 23:49:43 INFO Vacuumed table table=closures15712026/09/16 23:49:43 WARN Failed to register uploaded object key=dd98n8sb9ma6jn7hri1slccxh4jrqd0i.narinfo error="server returned 404: 404 page not found\n"15722026/09/16 23:49:43 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete15732026/09/16 23:49:43 INFO Completed upload id=115742026/09/16 23:49:43 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete15752026/09/16 23:49:43 INFO Vacuumed table table=objects15762026/09/16 23:49:43 INFO Completed upload id=215772026/09/16 23:49:43 INFO Received complete upload request method=POST path=/api/pending_closures/3/complete15782026/09/16 23:49:43 INFO Completed upload id=315792026/09/16 23:49:43 INFO Upload complete. (257ms)1580=== NAME TestClientMultipleUploads1581 client_integration_test.go:369: Uploaded 3 paths in 303.137292ms1582--- PASS: TestClientMultipleUploads (2.43s)1583=== CONT TestService_AuthMiddleware_MTLSBoundSubjects1584--- PASS: TestCacheStatsHandler (1.32s)1585=== CONT TestClientErrorHandling/ServerNotAvailable15862026-09-16 23:49:43.567 UTC [63401] ERROR: relation "goose_db_version" does not exist at character 3615872026-09-16 23:49:43.567 UTC [63401] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1588--- PASS: TestService_ReadAuthMiddleware (1.15s)1589=== CONT TestService_AuthMiddleware_MTLSProxyHeader15902026/09/16 23:49:43 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present15912026/09/16 23:49:43 OK 20241026095416_initial_model.sql (7.89ms)15922026/09/16 23:49:43 WARN Rate limiter enabled after throttle name=s3-test rate=515932026/09/16 23:49:43 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."1594=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle1595 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=101596 throttle_test.go:215: Rate limiter: enabled=true, rate=5.0015972026/09/16 23:49:43 OK 20251210153512_drop_unused_gin_index.sql (1.07ms)1598--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (6.77s)1599=== CONT TestResurrectedObjectNotDeleted16002026/09/16 23:49:43 OK 20251218171726_add_pins.sql (4.62ms)16012026/09/16 23:49:43 OK 20260628120000_add_object_size_and_stats.sql (29.95ms)16022026/09/16 23:49:43 OK 20260905000000_add_claims.sql (30.01ms)16032026/09/16 23:49:43 goose: successfully migrated database to version: 2026090500000016042026/09/16 23:49:43 OK 1_commit_pending_closure.sql (24.98ms)16052026/09/16 23:49:43 OK 2_object_stats_trigger.sql (12.22ms)16062026/09/16 23:49:43 goose: up to current file version: 216072026/09/16 23:49:43 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=203.693501ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present16082026-09-16 23:49:43.790 UTC [63412] ERROR: relation "goose_db_version" does not exist at character 3616092026-09-16 23:49:43.790 UTC [63412] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16102026/09/16 23:49:43 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=401.810078ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present16112026-09-16 23:49:43.950 UTC [63415] ERROR: relation "goose_db_version" does not exist at character 3616122026-09-16 23:49:43.950 UTC [63415] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16132026/09/16 23:49:43 OK 20241026095416_initial_model.sql (155.52ms)16142026/09/16 23:49:43 OK 20251210153512_drop_unused_gin_index.sql (16.62ms)16152026/09/16 23:49:43 OK 20251218171726_add_pins.sql (18.31ms)16162026/09/16 23:49:44 OK 20260628120000_add_object_size_and_stats.sql (41.66ms)16172026/09/16 23:49:44 OK 20260905000000_add_claims.sql (11.3ms)16182026/09/16 23:49:44 goose: successfully migrated database to version: 2026090500000016192026/09/16 23:49:44 OK 1_commit_pending_closure.sql (1.69ms)16202026/09/16 23:49:44 OK 2_object_stats_trigger.sql (639µs)16212026/09/16 23:49:44 goose: up to current file version: 21622=== RUN TestService_RequireScope_OIDC/builder_may_write1623=== PAUSE TestService_RequireScope_OIDC/builder_may_write1624=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1625=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1626=== RUN TestService_RequireScope_OIDC/ops_may_admin1627=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1628=== RUN TestService_RequireScope_OIDC/ops_may_not_write1629=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1630=== RUN TestService_RequireScope_OIDC/reader_may_not_write1631=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1632=== RUN TestService_RequireScope_OIDC/static_token_may_admin1633=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1634=== RUN TestService_RequireScope_OIDC/static_token_may_write1635=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1636=== RUN TestService_RequireScope_OIDC/reader_may_read1637=== PAUSE TestService_RequireScope_OIDC/reader_may_read1638=== RUN TestService_RequireScope_OIDC/writer_implies_read1639=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1640=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1641=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1642=== CONT TestReadProxyHead16432026/09/16 23:49:44 INFO Received complete multipart upload request method=POST path=/api/multipart/complete16442026/09/16 23:49:44 OK 20241026095416_initial_model.sql (170.36ms)16452026/09/16 23:49:44 OK 20251210153512_drop_unused_gin_index.sql (14.74ms)16462026/09/16 23:49:44 INFO Completed multipart upload object_key=nar/0000000000000000000000000000001100000000000000000000.nar.zst upload_id=ZjM5NDBkOGYtMjAyYS00Y2ZiLThhMzEtZTdjOTYxZGY3M2IzLmFiMDhhNjNlLTRjYzYtNGExYy1hMzg3LWQ1ZjQwNzcwMzk4M3gxNzg5NjAyNTgyOTg0NTUzMDAw parts=1016472026/09/16 23:49:44 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete16482026/09/16 23:49:44 INFO Completed upload id=116492026/09/16 23:49:44 WARN claim: cannot clear write deadline error="feature not supported"16502026/09/16 23:49:44 OK 20251218171726_add_pins.sql (23.88ms)16512026/09/16 23:49:44 WARN claim: cannot clear write deadline error="feature not supported"1652--- PASS: TestClaim_GCMarkedOutputCountsAsAbsent (2.84s)1653=== CONT TestReadProxyInvalidPath16542026/09/16 23:49:44 OK 20260628120000_add_object_size_and_stats.sql (44.25ms)16552026/09/16 23:49:44 OK 20260905000000_add_claims.sql (33.22ms)16562026/09/16 23:49:44 goose: successfully migrated database to version: 2026090500000016572026/09/16 23:49:44 OK 1_commit_pending_closure.sql (8.99ms)16582026/09/16 23:49:44 OK 2_object_stats_trigger.sql (700.33µs)16592026/09/16 23:49:44 goose: up to current file version: 216602026/09/16 23:49:44 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=835.426379ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present1661=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1662=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1663=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1664=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1665=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1666=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1667=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1668=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1669=== CONT TestReadProxy40416702026/09/16 23:49:44 INFO Received complete multipart upload request method=POST path=/api/multipart/complete16712026-09-16 23:49:44.466 UTC [63428] ERROR: relation "goose_db_version" does not exist at character 3616722026-09-16 23:49:44.466 UTC [63428] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16732026-09-16 23:49:44.472 UTC [63429] ERROR: relation "goose_db_version" does not exist at character 3616742026-09-16 23:49:44.472 UTC [63429] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16752026/09/16 23:49:44 INFO Completed multipart upload object_key=nar/0000000000000000000000000000001000000000000000000000.nar.zst upload_id=ZjM5NDBkOGYtMjAyYS00Y2ZiLThhMzEtZTdjOTYxZGY3M2IzLjYwNDAxN2E2LWFjN2YtNDVjZi05ZmJhLWRkY2M1MGIxZTJiZXgxNzg5NjAyNTgzMTczMjk5MDAw parts=1016762026/09/16 23:49:44 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign16772026/09/16 23:49:44 INFO Signed narinfos id=1 count=116782026/09/16 23:49:44 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete16792026/09/16 23:49:44 INFO Received uploads request method=POST path=/api/pending_closures16802026/09/16 23:49:44 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign16812026/09/16 23:49:44 INFO Signed narinfos id=2 count=116822026/09/16 23:49:44 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete16832026/09/16 23:49:44 INFO Completed upload id=216842026/09/16 23:49:44 WARN claim: cannot clear write deadline error="feature not supported"1685--- PASS: TestClaim_BuildWaitComplete (2.72s)1686=== CONT TestReadProxyNarStreaming16872026/09/16 23:49:44 OK 20241026095416_initial_model.sql (27.69ms)16882026/09/16 23:49:44 OK 20251210153512_drop_unused_gin_index.sql (13.86ms)16892026/09/16 23:49:44 OK 20241026095416_initial_model.sql (34.73ms)16902026/09/16 23:49:44 OK 20251218171726_add_pins.sql (13.88ms)16912026/09/16 23:49:44 OK 20251210153512_drop_unused_gin_index.sql (1.72ms)16922026/09/16 23:49:44 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=01693=== NAME TestPinProtectsFromGC1694 client_integration_test.go:730: Pin successfully protected closure from garbage collection16952026/09/16 23:49:44 OK 20251218171726_add_pins.sql (11.68ms)16962026/09/16 23:49:44 OK 20260628120000_add_object_size_and_stats.sql (14.82ms)16972026/09/16 23:49:44 OK 20260628120000_add_object_size_and_stats.sql (14.72ms)1698--- PASS: TestPinProtectsFromGC (4.93s)1699=== CONT TestReadProxyNarinfoAlreadyDecompressed17002026/09/16 23:49:44 OK 20260905000000_add_claims.sql (28.5ms)17012026/09/16 23:49:44 goose: successfully migrated database to version: 2026090500000017022026/09/16 23:49:44 OK 1_commit_pending_closure.sql (2.26ms)17032026/09/16 23:49:44 OK 2_object_stats_trigger.sql (382.79µs)17042026/09/16 23:49:44 goose: up to current file version: 217052026/09/16 23:49:44 OK 20260905000000_add_claims.sql (24.89ms)17062026/09/16 23:49:44 goose: successfully migrated database to version: 2026090500000017072026/09/16 23:49:44 OK 1_commit_pending_closure.sql (8.15ms)17082026/09/16 23:49:44 OK 2_object_stats_trigger.sql (264.08µs)17092026/09/16 23:49:44 goose: up to current file version: 217102026/09/16 23:49:44 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"17112026/09/16 23:49:44 WARN mTLS auth: bound subjects configured but subject DN unavailable17122026/09/16 23:49:44 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1713--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (1.34s)1714=== CONT TestReadProxyNarinfo17152026/09/16 23:49:44 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3003 objects_failed=01716=== NAME TestClientIntegration1717 client_integration_test.go:323: Objects in database after GC:1718 client_integration_test.go:323: Successfully deleted all objects with GC --force17192026-09-16 23:49:44.820 UTC [63436] ERROR: relation "goose_db_version" does not exist at character 3617202026-09-16 23:49:44.820 UTC [63436] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1721--- PASS: TestClientIntegration (4.30s)1722=== CONT TestIsValidCachePath1723=== RUN TestIsValidCachePath/narinfo1724=== PAUSE TestIsValidCachePath/narinfo1725=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars1726=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars1727=== RUN TestIsValidCachePath/nar_zst1728=== PAUSE TestIsValidCachePath/nar_zst1729=== RUN TestIsValidCachePath/nar_xz1730=== PAUSE TestIsValidCachePath/nar_xz1731=== RUN TestIsValidCachePath/nar_bz21732=== PAUSE TestIsValidCachePath/nar_bz21733=== RUN TestIsValidCachePath/nar_uncompressed1734=== PAUSE TestIsValidCachePath/nar_uncompressed1735=== RUN TestIsValidCachePath/ls1736=== PAUSE TestIsValidCachePath/ls1737=== RUN TestIsValidCachePath/log1738=== PAUSE TestIsValidCachePath/log1739=== RUN TestIsValidCachePath/realisation1740=== PAUSE TestIsValidCachePath/realisation1741=== RUN TestIsValidCachePath/nix-cache-info1742=== PAUSE TestIsValidCachePath/nix-cache-info1743=== RUN TestIsValidCachePath/index.html1744=== PAUSE TestIsValidCachePath/index.html1745=== RUN TestIsValidCachePath/traversal_parent1746=== PAUSE TestIsValidCachePath/traversal_parent1747=== RUN TestIsValidCachePath/traversal_in_middle1748=== PAUSE TestIsValidCachePath/traversal_in_middle1749=== RUN TestIsValidCachePath/invalid_char_e1750=== PAUSE TestIsValidCachePath/invalid_char_e1751=== RUN TestIsValidCachePath/invalid_char_u1752=== PAUSE TestIsValidCachePath/invalid_char_u1753=== RUN TestIsValidCachePath/random_path1754=== PAUSE TestIsValidCachePath/random_path1755=== RUN TestIsValidCachePath/empty1756=== PAUSE TestIsValidCachePath/empty1757=== RUN TestIsValidCachePath/leading_slash1758=== PAUSE TestIsValidCachePath/leading_slash1759=== RUN TestIsValidCachePath/wrong_extension1760=== PAUSE TestIsValidCachePath/wrong_extension1761=== RUN TestIsValidCachePath/short_hash1762=== PAUSE TestIsValidCachePath/short_hash1763=== CONT TestParseSingleRange1764=== RUN TestParseSingleRange/none1765=== PAUSE TestParseSingleRange/none1766=== RUN TestParseSingleRange/unknown_unit1767=== PAUSE TestParseSingleRange/unknown_unit1768=== RUN TestParseSingleRange/multi-range_ignored1769=== PAUSE TestParseSingleRange/multi-range_ignored1770=== RUN TestParseSingleRange/malformed_no_dash1771=== PAUSE TestParseSingleRange/malformed_no_dash1772=== RUN TestParseSingleRange/malformed_both_empty1773=== PAUSE TestParseSingleRange/malformed_both_empty1774=== RUN TestParseSingleRange/malformed_end_before_start1775=== PAUSE TestParseSingleRange/malformed_end_before_start1776=== RUN TestParseSingleRange/closed1777=== PAUSE TestParseSingleRange/closed1778=== RUN TestParseSingleRange/open-ended1779=== PAUSE TestParseSingleRange/open-ended1780=== RUN TestParseSingleRange/end_clamped_to_size1781=== PAUSE TestParseSingleRange/end_clamped_to_size1782=== RUN TestParseSingleRange/suffix1783=== PAUSE TestParseSingleRange/suffix1784=== RUN TestParseSingleRange/suffix_exceeds_size1785=== PAUSE TestParseSingleRange/suffix_exceeds_size1786=== RUN TestParseSingleRange/single_byte1787=== PAUSE TestParseSingleRange/single_byte1788=== RUN TestParseSingleRange/start_past_EOF1789=== PAUSE TestParseSingleRange/start_past_EOF1790=== RUN TestParseSingleRange/start_far_past_EOF1791=== PAUSE TestParseSingleRange/start_far_past_EOF1792=== CONT TestClientErrorHandling/InvalidAuthToken17932026/09/16 23:49:44 OK 20241026095416_initial_model.sql (61.9ms)17942026/09/16 23:49:44 OK 20251210153512_drop_unused_gin_index.sql (1.98ms)17952026/09/16 23:49:44 OK 20251218171726_add_pins.sql (26.47ms)1796--- PASS: TestResurrectedObjectNotDeleted (1.32s)1797=== CONT TestServerTLSConfig1798=== RUN TestServerTLSConfig/no_client_CA1799=== PAUSE TestServerTLSConfig/no_client_CA1800=== RUN TestServerTLSConfig/missing_CA_file1801=== PAUSE TestServerTLSConfig/missing_CA_file1802=== RUN TestServerTLSConfig/not_a_PEM_file1803=== PAUSE TestServerTLSConfig/not_a_PEM_file1804=== CONT TestOrphanedObjectsGCStressTest18052026-09-16 23:49:44.979 UTC [63442] ERROR: relation "goose_db_version" does not exist at character 3618062026-09-16 23:49:44.979 UTC [63442] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18072026/09/16 23:49:44 OK 20260628120000_add_object_size_and_stats.sql (42.86ms)18082026/09/16 23:49:44 OK 20260905000000_add_claims.sql (10.26ms)18092026/09/16 23:49:44 goose: successfully migrated database to version: 2026090500000018102026/09/16 23:49:45 OK 1_commit_pending_closure.sql (14.8ms)18112026/09/16 23:49:45 OK 2_object_stats_trigger.sql (10.29ms)18122026/09/16 23:49:45 goose: up to current file version: 218132026-09-16 23:49:45.066 UTC [63443] ERROR: relation "goose_db_version" does not exist at character 3618142026-09-16 23:49:45.066 UTC [63443] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18152026/09/16 23:49:45 OK 20241026095416_initial_model.sql (54.62ms)18162026/09/16 23:49:45 OK 20251210153512_drop_unused_gin_index.sql (12.64ms)1817--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (1.52s)1818=== CONT TestOrphanedObjectsGC18192026/09/16 23:49:45 OK 20251218171726_add_pins.sql (26.33ms)18202026/09/16 23:49:45 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.680431498s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present18212026/09/16 23:49:45 OK 20260628120000_add_object_size_and_stats.sql (43.91ms)18222026/09/16 23:49:45 OK 20241026095416_initial_model.sql (79.41ms)18232026/09/16 23:49:45 OK 20251210153512_drop_unused_gin_index.sql (13.36ms)18242026/09/16 23:49:45 OK 20260905000000_add_claims.sql (23.57ms)18252026/09/16 23:49:45 goose: successfully migrated database to version: 2026090500000018262026/09/16 23:49:45 OK 20251218171726_add_pins.sql (10.31ms)18272026/09/16 23:49:45 OK 1_commit_pending_closure.sql (2.26ms)18282026/09/16 23:49:45 OK 2_object_stats_trigger.sql (528.67µs)18292026/09/16 23:49:45 goose: up to current file version: 218302026/09/16 23:49:45 OK 20260628120000_add_object_size_and_stats.sql (25.97ms)18312026/09/16 23:49:45 OK 20260905000000_add_claims.sql (23.7ms)18322026/09/16 23:49:45 goose: successfully migrated database to version: 2026090500000018332026/09/16 23:49:45 OK 1_commit_pending_closure.sql (1.54ms)18342026/09/16 23:49:45 OK 2_object_stats_trigger.sql (279.54µs)18352026/09/16 23:49:45 goose: up to current file version: 21836--- PASS: TestReadProxyHead (1.26s)1837=== CONT TestObjectStatsTrigger18382026-09-16 23:49:45.464 UTC [63448] ERROR: relation "goose_db_version" does not exist at character 3618392026-09-16 23:49:45.464 UTC [63448] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18402026-09-16 23:49:45.492 UTC [63449] ERROR: relation "goose_db_version" does not exist at character 3618412026-09-16 23:49:45.492 UTC [63449] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18422026-09-16 23:49:45.498 UTC [63450] ERROR: relation "goose_db_version" does not exist at character 3618432026-09-16 23:49:45.498 UTC [63450] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18442026/09/16 23:49:45 OK 20241026095416_initial_model.sql (35.12ms)18452026/09/16 23:49:45 OK 20251210153512_drop_unused_gin_index.sql (7.46ms)18462026/09/16 23:49:45 OK 20251218171726_add_pins.sql (23.16ms)1847--- PASS: TestReadProxyInvalidPath (1.31s)1848=== CONT TestMultipartCleanup18492026/09/16 23:49:45 OK 20260628120000_add_object_size_and_stats.sql (6.75ms)18502026/09/16 23:49:45 OK 20241026095416_initial_model.sql (51.32ms)18512026/09/16 23:49:45 OK 20241026095416_initial_model.sql (50.47ms)18522026/09/16 23:49:45 OK 20251210153512_drop_unused_gin_index.sql (1.7ms)18532026/09/16 23:49:45 OK 20251210153512_drop_unused_gin_index.sql (1.74ms)18542026/09/16 23:49:45 OK 20251218171726_add_pins.sql (18.17ms)18552026/09/16 23:49:45 OK 20251218171726_add_pins.sql (26.22ms)18562026/09/16 23:49:45 OK 20260905000000_add_claims.sql (28.23ms)18572026/09/16 23:49:45 goose: successfully migrated database to version: 2026090500000018582026/09/16 23:49:45 OK 1_commit_pending_closure.sql (9.37ms)18592026/09/16 23:49:45 OK 20260628120000_add_object_size_and_stats.sql (18.31ms)18602026/09/16 23:49:45 OK 20260628120000_add_object_size_and_stats.sql (10.63ms)18612026/09/16 23:49:45 OK 2_object_stats_trigger.sql (1.19ms)18622026/09/16 23:49:45 goose: up to current file version: 218632026/09/16 23:49:45 OK 20260905000000_add_claims.sql (3.12ms)18642026/09/16 23:49:45 goose: successfully migrated database to version: 2026090500000018652026/09/16 23:49:45 OK 1_commit_pending_closure.sql (2.04ms)18662026/09/16 23:49:45 OK 2_object_stats_trigger.sql (312.33µs)18672026/09/16 23:49:45 goose: up to current file version: 218682026/09/16 23:49:45 OK 20260905000000_add_claims.sql (33.55ms)18692026/09/16 23:49:45 goose: successfully migrated database to version: 2026090500000018702026/09/16 23:49:45 OK 1_commit_pending_closure.sql (2.99ms)18712026/09/16 23:49:45 OK 2_object_stats_trigger.sql (339.92µs)18722026/09/16 23:49:45 goose: up to current file version: 218732026-09-16 23:49:45.691 UTC [63453] ERROR: relation "goose_db_version" does not exist at character 3618742026-09-16 23:49:45.691 UTC [63453] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1875--- PASS: TestReadProxy404 (1.40s)1876=== CONT TestMetricsInventory18772026-09-16 23:49:45.783 UTC [63456] ERROR: relation "goose_db_version" does not exist at character 3618782026-09-16 23:49:45.783 UTC [63456] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18792026/09/16 23:49:45 OK 20241026095416_initial_model.sql (76.99ms)18802026/09/16 23:49:45 OK 20251210153512_drop_unused_gin_index.sql (1.13ms)18812026/09/16 23:49:45 OK 20251218171726_add_pins.sql (8.83ms)18822026/09/16 23:49:45 OK 20260628120000_add_object_size_and_stats.sql (16.85ms)18832026/09/16 23:49:45 OK 20260905000000_add_claims.sql (11.32ms)18842026/09/16 23:49:45 goose: successfully migrated database to version: 2026090500000018852026/09/16 23:49:45 OK 1_commit_pending_closure.sql (9.36ms)18862026/09/16 23:49:45 OK 2_object_stats_trigger.sql (651.17µs)18872026/09/16 23:49:45 goose: up to current file version: 218882026/09/16 23:49:45 OK 20241026095416_initial_model.sql (61.96ms)18892026/09/16 23:49:45 OK 20251210153512_drop_unused_gin_index.sql (1.37ms)18902026/09/16 23:49:45 OK 20251218171726_add_pins.sql (18.15ms)18912026/09/16 23:49:45 OK 20260628120000_add_object_size_and_stats.sql (16.21ms)18922026/09/16 23:49:45 OK 20260905000000_add_claims.sql (23.62ms)18932026/09/16 23:49:45 goose: successfully migrated database to version: 2026090500000018942026/09/16 23:49:45 OK 1_commit_pending_closure.sql (2.27ms)18952026/09/16 23:49:45 OK 2_object_stats_trigger.sql (623.75µs)18962026/09/16 23:49:45 goose: up to current file version: 21897--- PASS: TestReadProxyNarinfoAlreadyDecompressed (1.35s)1898=== CONT TestService_NativeMTLS18992026-09-16 23:49:45.995 UTC [63463] ERROR: relation "goose_db_version" does not exist at character 3619002026-09-16 23:49:45.995 UTC [63463] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC19012026/09/16 23:49:46 OK 20241026095416_initial_model.sql (83.68ms)19022026/09/16 23:49:46 OK 20251210153512_drop_unused_gin_index.sql (1.23ms)1903--- PASS: TestReadProxyNarStreaming (1.59s)1904=== CONT TestNARDeduplicationMetadataUploadBug19052026/09/16 23:49:46 OK 20251218171726_add_pins.sql (10.36ms)19062026-09-16 23:49:46.123 UTC [63468] ERROR: relation "goose_db_version" does not exist at character 3619072026-09-16 23:49:46.123 UTC [63468] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC19082026/09/16 23:49:46 OK 20260628120000_add_object_size_and_stats.sql (22.11ms)19092026/09/16 23:49:46 OK 20260905000000_add_claims.sql (13.26ms)19102026/09/16 23:49:46 goose: successfully migrated database to version: 2026090500000019112026/09/16 23:49:46 OK 1_commit_pending_closure.sql (1.18ms)19122026/09/16 23:49:46 OK 2_object_stats_trigger.sql (281.08µs)19132026/09/16 23:49:46 goose: up to current file version: 219142026/09/16 23:49:46 OK 20241026095416_initial_model.sql (48.35ms)19152026/09/16 23:49:46 OK 20251210153512_drop_unused_gin_index.sql (7.06ms)19162026/09/16 23:49:46 OK 20251218171726_add_pins.sql (16.45ms)19172026/09/16 23:49:46 OK 20260628120000_add_object_size_and_stats.sql (20.41ms)19182026/09/16 23:49:46 OK 20260905000000_add_claims.sql (25.69ms)19192026/09/16 23:49:46 goose: successfully migrated database to version: 2026090500000019202026/09/16 23:49:46 OK 1_commit_pending_closure.sql (2.83ms)19212026/09/16 23:49:46 OK 2_object_stats_trigger.sql (618.04µs)19222026/09/16 23:49:46 goose: up to current file version: 21923--- PASS: TestReadProxyNarinfo (1.64s)1924=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure19252026/09/16 23:49:46 INFO Received uploads request method=POST path=/19262026-09-16 23:49:46.322 UTC [63473] ERROR: relation "goose_db_version" does not exist at character 3619272026-09-16 23:49:46.322 UTC [63473] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC19282026/09/16 23:49:46 OK 20241026095416_initial_model.sql (66.21ms)19292026/09/16 23:49:46 OK 20251210153512_drop_unused_gin_index.sql (6.86ms)19302026/09/16 23:49:46 OK 20251218171726_add_pins.sql (2.7ms)19312026/09/16 23:49:46 OK 20260628120000_add_object_size_and_stats.sql (18.97ms)19322026/09/16 23:49:46 OK 20260905000000_add_claims.sql (20.36ms)19332026/09/16 23:49:46 goose: successfully migrated database to version: 2026090500000019342026-09-16 23:49:46.479 UTC [63475] ERROR: relation "goose_db_version" does not exist at character 3619352026-09-16 23:49:46.479 UTC [63475] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC19362026/09/16 23:49:46 OK 1_commit_pending_closure.sql (1.69ms)19372026/09/16 23:49:46 OK 2_object_stats_trigger.sql (581.58µs)19382026/09/16 23:49:46 goose: up to current file version: 219392026/09/16 23:49:46 OK 20241026095416_initial_model.sql (46.61ms)19402026/09/16 23:49:46 OK 20251210153512_drop_unused_gin_index.sql (8.06ms)19412026/09/16 23:49:46 OK 20251218171726_add_pins.sql (13ms)19422026/09/16 23:49:46 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"19432026/09/16 23:49:46 OK 20260628120000_add_object_size_and_stats.sql (24.58ms)19442026/09/16 23:49:46 OK 20260905000000_add_claims.sql (10.96ms)19452026/09/16 23:49:46 goose: successfully migrated database to version: 2026090500000019462026/09/16 23:49:46 OK 1_commit_pending_closure.sql (2.17ms)19472026/09/16 23:49:46 OK 2_object_stats_trigger.sql (623.21µs)19482026/09/16 23:49:46 goose: up to current file version: 219492026-09-16 23:49:46.614 UTC [63480] ERROR: relation "goose_db_version" does not exist at character 3619502026-09-16 23:49:46.614 UTC [63480] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC19512026/09/16 23:49:46 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"19522026/09/16 23:49:46 OK 20241026095416_initial_model.sql (36.72ms)19532026/09/16 23:49:46 OK 20251210153512_drop_unused_gin_index.sql (1.56ms)19542026/09/16 23:49:46 OK 20251218171726_add_pins.sql (8.65ms)19552026/09/16 23:49:46 OK 20260628120000_add_object_size_and_stats.sql (14.29ms)19562026/09/16 23:49:46 OK 20260905000000_add_claims.sql (10.27ms)19572026/09/16 23:49:46 goose: successfully migrated database to version: 202609050000001958=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts19592026/09/16 23:49:46 INFO Received request for more parts method=POST path=/19602026-09-16 23:49:46.710 UTC [63484] ERROR: relation "goose_db_version" does not exist at character 3619612026-09-16 23:49:46.710 UTC [63484] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC19622026/09/16 23:49:46 OK 1_commit_pending_closure.sql (8.55ms)19632026/09/16 23:49:46 OK 2_object_stats_trigger.sql (294.17µs)19642026/09/16 23:49:46 goose: up to current file version: 21965=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart19662026/09/16 23:49:46 INFO Received complete multipart upload request method=POST path=/19672026/09/16 23:49:46 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"1968=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info19692026/09/16 23:49:46 INFO Received uploads request method=POST path=/1970=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key19712026/09/16 23:49:46 INFO Received complete multipart upload request method=POST path=/1972=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key19732026/09/16 23:49:46 INFO Received request for more parts method=POST path=/1974=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal19752026/09/16 23:49:46 INFO Received uploads request method=POST path=/1976--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)1977 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1978 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1979 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1980 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1981=== CONT TestIsValidUploadKey/narinfo1982=== CONT TestIsValidUploadKey/realisation_plus_in_output1983=== CONT TestIsValidUploadKey/unknown_type1984=== CONT TestIsValidUploadKey/empty_key1985=== CONT TestIsValidUploadKey/absolute1986=== CONT TestIsValidUploadKey/traversal_nar1987=== CONT TestIsValidUploadKey/traversal1988=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1989=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1990=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1991=== CONT TestIsValidUploadKey/index.html1992=== CONT TestIsValidUploadKey/nix-cache-info1993=== CONT TestIsValidUploadKey/build_log_home-manager_file1994=== CONT TestIsValidUploadKey/realisation1995=== CONT TestIsValidUploadKey/build_log_equals1996=== CONT TestIsValidUploadKey/build_log_question_mark1997=== CONT TestIsValidUploadKey/build_log_plus_in_name1998=== CONT TestIsValidUploadKey/nar_plain1999=== CONT TestIsValidUploadKey/build_log2000=== CONT TestIsValidUploadKey/listing2001=== CONT TestIsValidUploadKey/nar_xz2002=== CONT TestIsValidUploadKey/nar_zst2003=== CONT TestProxyWriteTimeout/narinfo2004=== CONT TestProxyWriteTimeout/10_GiB_nar2005--- PASS: TestIsValidUploadKey (0.01s)2006 --- PASS: TestIsValidUploadKey/narinfo (0.00s)2007 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)2008 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)2009 --- PASS: TestIsValidUploadKey/empty_key (0.00s)2010 --- PASS: TestIsValidUploadKey/absolute (0.00s)2011 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)2012 --- PASS: TestIsValidUploadKey/traversal (0.00s)2013 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)2014 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)2015 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)2016 --- PASS: TestIsValidUploadKey/index.html (0.00s)2017 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)2018 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)2019 --- PASS: TestIsValidUploadKey/realisation (0.00s)2020 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)2021 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)2022 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)2023 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)2024 --- PASS: TestIsValidUploadKey/build_log (0.00s)2025 --- PASS: TestIsValidUploadKey/listing (0.00s)2026 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)2027 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)2028=== CONT TestProxyWriteTimeout/unknown_size2029=== CONT TestProxyWriteTimeout/1_GiB_nar2030--- PASS: TestProxyWriteTimeout (0.00s)2031 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)2032 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)2033 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)2034 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)2035=== CONT TestResolveDBConnectionString/flag_wins2036=== CONT TestResolveDBConnectionString/PGHOST_allows_empty2037=== CONT TestResolveDBConnectionString/nothing_configured2038=== CONT TestResolveDBConnectionString/missing_file_is_an_error2039=== CONT TestResolveDBConnectionString/file_when_flag_empty2040=== CONT TestCacheConfigHandler/full_config,_no_issuer2041=== CONT TestCacheConfigHandler/no_signing_keys2042=== CONT TestCacheConfigHandler/no_cache_url_configured2043=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator2044--- PASS: TestCacheConfigHandler (0.00s)2045 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)2046 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)2047 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)2048 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)2049=== CONT TestService_RequireScope_OIDC/builder_may_write2050--- PASS: TestUploadHandlersRejectOversizedBody (0.08s)2051 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.44s)2052 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.02s)2053 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.03s)2054=== CONT TestService_RequireScope_OIDC/static_token_may_admin2055=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read2056=== CONT TestService_RequireScope_OIDC/writer_implies_read20572026/09/16 23:49:46 INFO OIDC auth successful provider=test scopes=[write]2058=== CONT TestService_RequireScope_OIDC/reader_may_read20592026/09/16 23:49:46 INFO OIDC auth successful provider=test scopes=[write]2060=== CONT TestService_RequireScope_OIDC/static_token_may_write2061=== CONT TestService_RequireScope_OIDC/ops_may_not_write20622026/09/16 23:49:46 INFO OIDC auth successful provider=test scopes=[read]2063=== CONT TestService_RequireScope_OIDC/reader_may_not_write20642026/09/16 23:49:46 INFO OIDC auth successful provider=test scopes=[admin]2065=== CONT TestService_RequireScope_OIDC/ops_may_admin20662026/09/16 23:49:46 INFO OIDC auth successful provider=test scopes=[read]2067=== CONT TestService_RequireScope_OIDC/builder_may_not_admin20682026/09/16 23:49:46 INFO OIDC auth successful provider=test scopes=[admin]2069=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token20702026/09/16 23:49:46 INFO OIDC auth successful provider=test scopes=[write]2071=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected20722026/09/16 23:49:46 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]2073=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2074=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected2075--- PASS: TestResolveDBConnectionString (0.01s)2076 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)2077 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)2078 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)2079 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)2080 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)2081--- PASS: TestService_RequireScope_OIDC (1.27s)2082 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)2083 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)2084 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)2085 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)2086 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)2087 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)2088 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)2089 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)2090 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)2091 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)20922026/09/16 23:49:46 WARN Authentication failed token_preview=eyJhbGciOi...pfBnsRx7NA token_length=702 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]2093=== CONT TestIsValidCachePath/narinfo2094=== CONT TestIsValidCachePath/index.html20952026/09/16 23:49:46 INFO OIDC auth successful provider=test scopes=[write]2096=== CONT TestIsValidCachePath/short_hash2097=== CONT TestIsValidCachePath/leading_slash2098=== CONT TestIsValidCachePath/empty2099=== CONT TestIsValidCachePath/random_path2100=== CONT TestIsValidCachePath/invalid_char_u2101=== CONT TestIsValidCachePath/invalid_char_e2102=== CONT TestIsValidCachePath/traversal_in_middle2103=== CONT TestIsValidCachePath/traversal_parent2104=== CONT TestIsValidCachePath/nar_uncompressed2105=== CONT TestIsValidCachePath/nix-cache-info2106=== CONT TestIsValidCachePath/realisation2107=== CONT TestIsValidCachePath/log2108=== CONT TestIsValidCachePath/ls2109=== CONT TestIsValidCachePath/nar_xz2110=== CONT TestParseSingleRange/none2111=== CONT TestIsValidCachePath/nar_bz22112=== CONT TestIsValidCachePath/nar_zst2113=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars2114=== CONT TestParseSingleRange/open-ended2115=== CONT TestParseSingleRange/start_far_past_EOF2116=== CONT TestParseSingleRange/start_past_EOF2117=== CONT TestParseSingleRange/single_byte2118=== CONT TestParseSingleRange/suffix_exceeds_size2119=== CONT TestParseSingleRange/suffix2120=== CONT TestParseSingleRange/end_clamped_to_size2121=== CONT TestParseSingleRange/malformed_both_empty2122=== CONT TestParseSingleRange/closed2123=== CONT TestParseSingleRange/malformed_end_before_start2124=== CONT TestParseSingleRange/multi-range_ignored2125=== CONT TestParseSingleRange/malformed_no_dash2126=== CONT TestParseSingleRange/unknown_unit2127--- PASS: TestParseSingleRange (0.00s)2128 --- PASS: TestParseSingleRange/none (0.00s)2129 --- PASS: TestParseSingleRange/open-ended (0.00s)2130 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)2131 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)2132 --- PASS: TestParseSingleRange/single_byte (0.00s)2133 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)2134 --- PASS: TestParseSingleRange/suffix (0.00s)2135 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)2136 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)2137 --- PASS: TestParseSingleRange/closed (0.00s)2138 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)2139 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)2140 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)2141 --- PASS: TestParseSingleRange/unknown_unit (0.00s)2142=== CONT TestServerTLSConfig/no_client_CA2143=== CONT TestServerTLSConfig/not_a_PEM_file2144=== CONT TestIsValidCachePath/wrong_extension2145--- PASS: TestIsValidCachePath (0.00s)2146 --- PASS: TestIsValidCachePath/narinfo (0.00s)2147 --- PASS: TestIsValidCachePath/index.html (0.00s)2148 --- PASS: TestIsValidCachePath/short_hash (0.00s)2149 --- PASS: TestIsValidCachePath/leading_slash (0.00s)2150 --- PASS: TestIsValidCachePath/empty (0.00s)2151 --- PASS: TestIsValidCachePath/random_path (0.00s)2152 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)2153 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)2154 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)2155 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)2156 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)2157 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)2158 --- PASS: TestIsValidCachePath/realisation (0.00s)2159 --- PASS: TestIsValidCachePath/log (0.00s)2160 --- PASS: TestIsValidCachePath/ls (0.00s)2161 --- PASS: TestIsValidCachePath/nar_xz (0.00s)2162 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)2163 --- PASS: TestIsValidCachePath/nar_zst (0.00s)2164 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)2165 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)2166=== CONT TestServerTLSConfig/missing_CA_file2167--- PASS: TestService_AuthMiddleware_OIDC (1.27s)2168 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)2169 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)2170 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)2171 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)2172--- PASS: TestServerTLSConfig (0.00s)2173 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)2174 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)2175 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)21762026/09/16 23:49:46 OK 20241026095416_initial_model.sql (29.34ms)21772026/09/16 23:49:46 OK 20251210153512_drop_unused_gin_index.sql (5.19ms)21782026/09/16 23:49:46 OK 20251218171726_add_pins.sql (5.71ms)21792026/09/16 23:49:46 OK 20260628120000_add_object_size_and_stats.sql (9.43ms)21802026/09/16 23:49:46 OK 20260905000000_add_claims.sql (3.87ms)21812026/09/16 23:49:46 goose: successfully migrated database to version: 2026090500000021822026/09/16 23:49:46 OK 1_commit_pending_closure.sql (16.82ms)21832026/09/16 23:49:46 OK 2_object_stats_trigger.sql (13.15ms)21842026/09/16 23:49:46 goose: up to current file version: 221852026/09/16 23:49:46 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-config2186--- PASS: TestObjectStatsTrigger (1.63s)21872026/09/16 23:49:47 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=214.201372ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21882026/09/16 23:49:47 INFO Received uploads request method=POST path=/api/pending_closures2189=== NAME TestOrphanedObjectsGC2190 orphaned_objects_gc_test.go:290: GC Test Summary:2191 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A2192 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B2193 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)2194 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)2195 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects2196--- PASS: TestOrphanedObjectsGC (2.09s)21972026/09/16 23:49:47 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=439.972278ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21982026/09/16 23:49:47 INFO Received cleanup request method=DELETE path=/api/pending_closures21992026/09/16 23:49:47 INFO Aborted multipart uploads count=12200--- PASS: TestMultipartCleanup (1.76s)2201--- PASS: TestMetricsInventory (1.63s)22022026/09/16 23:49:47 WARN mTLS auth: subject not in bound subjects subject="CN=reader"22032026/09/16 23:49:47 WARN mTLS auth: subject not in bound subjects subject="CN=reader"2204--- PASS: TestService_NativeMTLS (1.60s)22052026/09/16 23:49:47 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=855.730674ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2206=== NAME TestNARDeduplicationMetadataUploadBug2207 metadata_upload_test.go:48: First store path: /nix/var/nix/builds/nix-62631-4145625453/TestNARDeduplicationMetadataUploadBug2260107942/001/store/29d3kx10l6rz61x1r2yfzf517byxkpxd-file1.txt22082026/09/16 23:49:47 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"22092026/09/16 23:49:47 INFO Received uploads request method=POST path=/api/pending_closures22102026/09/16 23:49:47 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)22112026/09/16 23:49:47 INFO Uploading 29d3kx10l6rz61x1r2yfzf517byxkpxd-file1.txt (160B)22122026/09/16 23:49:47 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"22132026/09/16 23:49:47 WARN Failed to register uploaded object key=29d3kx10l6rz61x1r2yfzf517byxkpxd.ls error="server returned 404: 404 page not found\n"22142026/09/16 23:49:47 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign22152026/09/16 23:49:47 INFO Signed narinfos id=1 count=122162026/09/16 23:49:47 INFO Uploading 1 narinfos22172026/09/16 23:49:48 WARN Failed to register uploaded object key=29d3kx10l6rz61x1r2yfzf517byxkpxd.narinfo error="server returned 404: 404 page not found\n"22182026/09/16 23:49:48 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete22192026/09/16 23:49:48 INFO Completed upload id=122202026/09/16 23:49:48 INFO Upload complete. (122ms)2221 metadata_upload_test.go:54: Retrieved narinfo from S3:2222 StorePath: /nix/var/nix/builds/nix-62631-4145625453/TestNARDeduplicationMetadataUploadBug2260107942/001/store/29d3kx10l6rz61x1r2yfzf517byxkpxd-file1.txt2223 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst2224 Compression: zstd2225 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf2226 NarSize: 1602227 References: 2228 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf2229 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)2230 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):2231 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}2232 metadata_upload_test.go:64: Second store path (same content): /nix/var/nix/builds/nix-62631-4145625453/TestNARDeduplicationMetadataUploadBug2260107942/001/store/k9vv9zxvrc6k04d3rhk272s3r6y6nalk-file2.txt22332026/09/16 23:49:48 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"22342026/09/16 23:49:48 INFO Received uploads request method=POST path=/api/pending_closures22352026/09/16 23:49:48 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)22362026/09/16 23:49:48 WARN Failed to register uploaded object key=k9vv9zxvrc6k04d3rhk272s3r6y6nalk.ls error="server returned 404: 404 page not found\n"22372026/09/16 23:49:48 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign22382026/09/16 23:49:48 INFO Signed narinfos id=2 count=122392026/09/16 23:49:48 INFO Uploading 1 narinfos22402026/09/16 23:49:48 WARN Failed to register uploaded object key=k9vv9zxvrc6k04d3rhk272s3r6y6nalk.narinfo error="server returned 404: 404 page not found\n"22412026/09/16 23:49:48 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete22422026/09/16 23:49:48 INFO Completed upload id=222432026/09/16 23:49:48 INFO Upload complete. (104ms)2244 metadata_upload_test.go:76: Retrieved narinfo from S3:2245 StorePath: /nix/var/nix/builds/nix-62631-4145625453/TestNARDeduplicationMetadataUploadBug2260107942/001/store/k9vv9zxvrc6k04d3rhk272s3r6y6nalk-file2.txt2246 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst2247 Compression: zstd2248 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf2249 NarSize: 1602250 References: 2251 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf2252 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)2253 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):2254 {"version":1,"root":{"type":"regular","size":44}}2255--- PASS: TestNARDeduplicationMetadataUploadBug (2.10s)2256=== NAME TestOrphanedObjectsGCStressTest2257 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains2258 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion22592026/09/16 23:49:48 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.470446452s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2260 orphaned_objects_gc_test.go:509: Stress test completed successfully:2261 orphaned_objects_gc_test.go:510: - Active objects preserved: 202262 orphaned_objects_gc_test.go:511: - Objects deleted: 2102263 orphaned_objects_gc_test.go:512: - Total GC'd: 2102264--- PASS: TestOrphanedObjectsGCStressTest (3.76s)22652026/09/16 23:49:50 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"22662026/09/16 23:49:50 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_closures22672026/09/16 23:49:50 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=211.666481ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22682026/09/16 23:49:50 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=370.428194ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22692026/09/16 23:49:50 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=876.742473ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22702026/09/16 23:49:51 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.739505495s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2271--- PASS: TestClientErrorHandling (0.00s)2272 --- PASS: TestClientErrorHandling/InvalidStorePath (1.46s)2273 --- PASS: TestClientErrorHandling/InvalidAuthToken (1.93s)2274 --- PASS: TestClientErrorHandling/ServerNotAvailable (10.06s)2275FAIL2276{"timestamp":"2026-09-16T23:49:53.470906Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:61093","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(11)"}22772026-09-16 23:49:53.574 UTC [62919] LOG: received smart shutdown request22782026-09-16 23:49:53.584 UTC [62919] LOG: background worker "logical replication launcher" (PID 62930) exited with exit code 122792026-09-16 23:49:53.589 UTC [62924] LOG: shutting down22802026-09-16 23:49:53.590 UTC [62924] LOG: checkpoint starting: shutdown immediate22812026-09-16 23:49:55.245 UTC [62924] LOG: checkpoint complete: wrote 13011 buffers (79.4%), wrote 3 SLRU buffers; 0 WAL file(s) added, 0 removed, 18 recycled; write=0.961 s, sync=0.681 s, total=1.656 s; sync files=21338, longest=0.009 s, average=0.001 s; distance=292400 kB, estimate=292400 kB; lsn=0/135192F0, redo lsn=0/135192F022822026-09-16 23:49:55.256 UTC [62919] LOG: database system is shut down