niks3-go-unit-tests
checks.aarch64-darwin.go-unit-tests
· build #225
· raw
1Running client tests...2=== RUN TestDoServerRequestAttachesToken3=== PAUSE TestDoServerRequestAttachesToken4=== RUN TestRegisterUploadedObjectReusesConnections5=== PAUSE TestRegisterUploadedObjectReusesConnections6=== RUN TestCaseHackSuffix7=== PAUSE TestCaseHackSuffix8=== RUN TestFilterOversizedClosures9=== PAUSE TestFilterOversizedClosures10=== RUN TestPartSizeForNAR11=== PAUSE TestPartSizeForNAR12=== RUN TestUploadMultipart_SupersededByPeer13=== PAUSE TestUploadMultipart_SupersededByPeer14=== RUN TestDumpPathCaseHackMatchesNix15--- PASS: TestDumpPathCaseHackMatchesNix (0.06s)16=== RUN TestDumpPathCaseHackCollision17--- PASS: TestDumpPathCaseHackCollision (0.00s)18=== RUN TestDumpPathMatchesNix19=== PAUSE TestDumpPathMatchesNix20=== RUN TestDumpPathSingleFile21=== PAUSE TestDumpPathSingleFile22=== RUN TestDumpPathWriterError23=== PAUSE TestDumpPathWriterError24=== RUN TestEncodeNixBase3225=== PAUSE TestEncodeNixBase3226=== RUN TestEncodeNixBase32WithRealHash27=== PAUSE TestEncodeNixBase32WithRealHash28=== RUN TestConvertHashToNix3229=== PAUSE TestConvertHashToNix3230=== RUN TestGetStorePathHash31=== PAUSE TestGetStorePathHash32=== RUN TestPathInfoHashCompatibility33=== PAUSE TestPathInfoHashCompatibility34=== RUN TestParsePathInfoJSON35=== PAUSE TestParsePathInfoJSON36=== RUN TestParsePathInfoJSONMultiplePaths37=== PAUSE TestParsePathInfoJSONMultiplePaths38=== RUN TestPathInfoCACompatibility39=== PAUSE TestPathInfoCACompatibility40=== RUN TestRateLimiterFeedback41=== PAUSE TestRateLimiterFeedback42=== RUN TestRateLimiterFeedback_400DoesNotCountAsSuccess43=== PAUSE TestRateLimiterFeedback_400DoesNotCountAsSuccess44=== RUN TestResolveStorePath45=== PAUSE TestResolveStorePath46=== RUN TestDoWithRetry_BodyReplayedViaGetBody47=== PAUSE TestDoWithRetry_BodyReplayedViaGetBody48=== RUN TestShellSplit49=== PAUSE TestShellSplit50=== RUN TestShellSplitErrors51=== PAUSE TestShellSplitErrors52=== RUN TestStreamPushReportsEveryPath53=== PAUSE TestStreamPushReportsEveryPath54=== RUN TestStreamPushBatchesUnderLoad55=== PAUSE TestStreamPushBatchesUnderLoad56=== RUN TestStreamPushIsolatesFailures57=== PAUSE TestStreamPushIsolatesFailures58=== RUN TestStreamPushGivesUpOnDeadServer59=== PAUSE TestStreamPushGivesUpOnDeadServer60=== RUN TestStreamPushRequestLine61=== PAUSE TestStreamPushRequestLine62=== RUN TestSetClientTLS63=== PAUSE TestSetClientTLS64=== RUN TestSetClientTLSDoesNotMutateDefaultTransport65=== PAUSE TestSetClientTLSDoesNotMutateDefaultTransport66=== RUN TestSetClientTLSErrors67=== PAUSE TestSetClientTLSErrors68=== RUN TestStaticToken69=== PAUSE TestStaticToken70=== RUN TestFileTokenReadsAndCaches71=== PAUSE TestFileTokenReadsAndCaches72=== RUN TestFileTokenMissing73=== PAUSE TestFileTokenMissing74=== RUN TestFileTokenEmpty75=== PAUSE TestFileTokenEmpty76=== RUN TestScriptTokenNoExpiryRerunsEveryCall77=== PAUSE TestScriptTokenNoExpiryRerunsEveryCall78=== RUN TestScriptTokenCachesUntilRefresh79=== PAUSE TestScriptTokenCachesUntilRefresh80=== RUN TestScriptTokenEmptyToken81=== PAUSE TestScriptTokenEmptyToken82=== RUN TestScriptTokenBadJSON83=== PAUSE TestScriptTokenBadJSON84=== RUN TestScriptTokenScriptFails85=== PAUSE TestScriptTokenScriptFails86=== RUN TestScriptTokenEmptyCommand87=== PAUSE TestScriptTokenEmptyCommand88=== CONT TestDoServerRequestAttachesToken89=== CONT TestShellSplit90=== CONT TestStaticToken91--- PASS: TestStaticToken (0.00s)92=== CONT TestFileTokenMissing93=== CONT TestScriptTokenEmptyCommand94--- PASS: TestShellSplit (0.00s)95--- PASS: TestScriptTokenEmptyCommand (0.00s)96=== CONT TestConvertHashToNix3297=== RUN TestConvertHashToNix32/SRI_format_to_Nix3298=== CONT TestScriptTokenScriptFails99=== CONT TestScriptTokenBadJSON100=== CONT TestScriptTokenEmptyToken101=== CONT TestScriptTokenCachesUntilRefresh102=== CONT TestScriptTokenNoExpiryRerunsEveryCall103=== CONT TestFileTokenEmpty104--- PASS: TestFileTokenMissing (0.00s)105=== CONT TestDoWithRetry_BodyReplayedViaGetBody106=== CONT TestFileTokenReadsAndCaches107=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32108=== RUN TestConvertHashToNix32/already_Nix32_format109=== PAUSE TestConvertHashToNix32/already_Nix32_format110=== RUN TestConvertHashToNix32/invalid_format111=== PAUSE TestConvertHashToNix32/invalid_format112=== CONT TestResolveStorePath113--- PASS: TestFileTokenEmpty (0.00s)114=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess115--- PASS: TestFileTokenReadsAndCaches (0.00s)116=== CONT TestRateLimiterFeedback117=== RUN TestRateLimiterFeedback/429_enables_limiter118--- PASS: TestResolveStorePath (0.00s)119=== CONT TestPathInfoCACompatibility120=== RUN TestPathInfoCACompatibility/null_ca_field121=== PAUSE TestPathInfoCACompatibility/null_ca_field122=== RUN TestPathInfoCACompatibility/old_string_format_-_text123=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text1242026/09/20 10:38:08 WARN Rate limiter enabled after throttle name=server-test rate=5125=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive126=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive127=== RUN TestPathInfoCACompatibility/new_structured_format_-_text128=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text129=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method130=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method131=== CONT TestParsePathInfoJSONMultiplePaths132=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths133=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths134=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths135=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths136=== CONT TestParsePathInfoJSON137=== RUN TestParsePathInfoJSON/Nix_format138=== PAUSE TestParsePathInfoJSON/Nix_format139=== RUN TestParsePathInfoJSON/Lix_format140=== PAUSE TestParsePathInfoJSON/Lix_format141=== RUN TestParsePathInfoJSON/empty_input142=== PAUSE TestParsePathInfoJSON/empty_input143=== RUN TestParsePathInfoJSON/whitespace_only144=== PAUSE TestParsePathInfoJSON/whitespace_only145=== RUN TestParsePathInfoJSON/invalid_JSON146=== PAUSE TestParsePathInfoJSON/invalid_JSON147=== CONT TestPathInfoHashCompatibility148=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)149=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)150=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon151=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon152=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI153=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI154=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512155=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512156=== PAUSE TestRateLimiterFeedback/429_enables_limiter157=== RUN TestRateLimiterFeedback/503_enables_limiter158=== PAUSE TestRateLimiterFeedback/503_enables_limiter159=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter160=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter161=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter162=== CONT TestGetStorePathHash163=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter164=== CONT TestFilterOversizedClosures165=== RUN TestGetStorePathHash/valid_store_path166=== RUN TestFilterOversizedClosures/no_limit_keeps_everything167--- PASS: TestScriptTokenScriptFails (0.01s)168=== CONT TestUploadMultipart_SupersededByPeer169=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything170=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped171=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped172=== RUN TestFilterOversizedClosures/all_closures_skipped173=== PAUSE TestFilterOversizedClosures/all_closures_skipped174=== RUN TestUploadMultipart_SupersededByPeer/exists175=== PAUSE TestUploadMultipart_SupersededByPeer/exists176=== RUN TestUploadMultipart_SupersededByPeer/missing177=== PAUSE TestUploadMultipart_SupersededByPeer/missing178=== CONT TestPartSizeForNAR179=== RUN TestPartSizeForNAR/zero_stays_at_minimum180=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum181=== RUN TestPartSizeForNAR/small_stays_at_minimum182=== PAUSE TestPartSizeForNAR/small_stays_at_minimum183=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum184=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum185=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts186=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts187=== RUN TestPartSizeForNAR/1_TiB1882026/09/20 10:38:08 WARN Rate limiter enabled after throttle name=server-test rate=5189=== CONT TestStreamPushGivesUpOnDeadServer190=== PAUSE TestPartSizeForNAR/1_TiB191=== RUN TestPartSizeForNAR/5_TiB_S3_max_object192=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object193=== RUN TestPartSizeForNAR/capped_at_5_GiB194=== PAUSE TestPartSizeForNAR/capped_at_5_GiB1952026/09/20 10:38:08 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:54397196=== CONT TestSetClientTLSErrors197--- PASS: TestDoServerRequestAttachesToken (0.01s)198=== CONT TestSetClientTLSDoesNotMutateDefaultTransport199=== PAUSE TestGetStorePathHash/valid_store_path200=== RUN TestGetStorePathHash/basename_without_hyphen_should_error201=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error202=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error203=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error204=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error205=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error206=== CONT TestSetClientTLS2072026/09/20 10:38:08 ERROR Upload failed error="connection refused" count=202082026/09/20 10:38:08 ERROR Server seems unavailable, giving up on batch untried=17209--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)210=== CONT TestStreamPushRequestLine2112026/09/20 10:38:08 WARN Rate limiter backed off name=server-test rate=52122026/09/20 10:38:08 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:543972132026/09/20 10:38:08 ERROR Upload failed error=boom count=1214--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.01s)215=== CONT TestEncodeNixBase32216=== RUN TestEncodeNixBase32/test_string_hash217=== PAUSE TestEncodeNixBase32/test_string_hash218=== RUN TestEncodeNixBase32/empty_input219=== PAUSE TestEncodeNixBase32/empty_input220=== CONT TestEncodeNixBase32WithRealHash221--- PASS: TestEncodeNixBase32WithRealHash (0.00s)222=== CONT TestDumpPathMatchesNix223=== RUN TestSetClientTLSErrors/missing_cert_file224=== PAUSE TestSetClientTLSErrors/missing_cert_file225=== RUN TestSetClientTLSErrors/missing_key_file226=== PAUSE TestSetClientTLSErrors/missing_key_file227=== RUN TestSetClientTLSErrors/missing_ca_file228=== PAUSE TestSetClientTLSErrors/missing_ca_file229=== RUN TestSetClientTLSErrors/invalid_ca_file230=== PAUSE TestSetClientTLSErrors/invalid_ca_file231=== CONT TestDumpPathWriterError232--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.00s)233=== CONT TestDumpPathSingleFile234=== RUN TestSetClientTLS/rejects_connection_without_client_cert235=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert236=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA237=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA238=== RUN TestSetClientTLS/preserves_debug_logging_transport239=== PAUSE TestSetClientTLS/preserves_debug_logging_transport240=== CONT TestStreamPushIsolatesFailures2412026/09/20 10:38:08 ERROR Upload failed error="bad path" count=3242--- PASS: TestStreamPushIsolatesFailures (0.00s)243=== CONT TestStreamPushReportsEveryPath244--- PASS: TestStreamPushReportsEveryPath (0.00s)245=== CONT TestShellSplitErrors246--- PASS: TestShellSplitErrors (0.00s)247=== CONT TestCaseHackSuffix248--- PASS: TestScriptTokenBadJSON (0.01s)249=== CONT TestRegisterUploadedObjectReusesConnections250--- PASS: TestScriptTokenEmptyToken (0.01s)251=== CONT TestStreamPushBatchesUnderLoad252--- PASS: TestStreamPushRequestLine (0.02s)253=== CONT TestConvertHashToNix32/SRI_format_to_Nix32254=== CONT TestConvertHashToNix32/invalid_format255=== CONT TestConvertHashToNix32/already_Nix32_format256--- PASS: TestConvertHashToNix32 (0.00s)257 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)258 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)259 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)260=== CONT TestPathInfoCACompatibility/null_ca_field261=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths262=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method263=== CONT TestPathInfoCACompatibility/new_structured_format_-_text264=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive265=== CONT TestPathInfoCACompatibility/old_string_format_-_text266--- PASS: TestPathInfoCACompatibility (0.00s)267 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)268 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)269 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)270 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)271 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)272=== 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 TestParsePathInfoJSON/Nix_format277=== CONT TestParsePathInfoJSON/whitespace_only278=== CONT TestParsePathInfoJSON/invalid_JSON279=== CONT TestParsePathInfoJSON/Lix_format280=== CONT TestParsePathInfoJSON/empty_input281--- PASS: TestParsePathInfoJSON (0.00s)282 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)283 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)284 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)285 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)286 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)287=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)288=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512289=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI290=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon291=== CONT TestRateLimiterFeedback/429_enables_limiter292--- PASS: TestPathInfoHashCompatibility (0.00s)293 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)294 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)295 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)296 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)2972026/09/20 10:38:08 WARN Rate limiter enabled after throttle name=server-test rate=52982026/09/20 10:38:08 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:54467299--- PASS: TestScriptTokenCachesUntilRefresh (0.04s)300=== CONT TestRateLimiterFeedback/503_enables_limiter301--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.04s)302=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter3032026/09/20 10:38:08 WARN Rate limiter backed off name=server-test rate=53042026/09/20 10:38:08 WARN Rate limiter enabled after throttle name=server-test rate=5305=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter3062026/09/20 10:38:08 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:544693072026/09/20 10:38:08 WARN Rate limiter backed off name=server-test rate=5308=== CONT TestFilterOversizedClosures/no_limit_keeps_everything309=== CONT TestUploadMultipart_SupersededByPeer/exists310=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped3112026/09/20 10:38:08 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=2000312=== CONT TestUploadMultipart_SupersededByPeer/missing313=== CONT TestFilterOversizedClosures/all_closures_skipped3142026/09/20 10:38:08 WARN Skipping closure: path exceeds server max NAR size top_level_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper oversized_path=/nix/store/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa-small nar_size=1000 max_nar_size=50315--- PASS: TestRateLimiterFeedback (0.00s)316 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.01s)317 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)318 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)319 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)320--- PASS: TestFilterOversizedClosures (0.00s)321 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)322 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)323 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)324=== CONT TestPartSizeForNAR/zero_stays_at_minimum325=== CONT TestPartSizeForNAR/1_TiB326=== CONT TestPartSizeForNAR/capped_at_5_GiB327=== CONT TestPartSizeForNAR/5_TiB_S3_max_object328=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum329=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts330=== CONT TestPartSizeForNAR/small_stays_at_minimum331--- PASS: TestPartSizeForNAR (0.00s)332 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)333 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)334 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)335 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)336 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)337 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)338 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)339=== CONT TestGetStorePathHash/valid_store_path340=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error341=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error342=== CONT TestGetStorePathHash/basename_without_hyphen_should_error343--- PASS: TestGetStorePathHash (0.00s)344 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)345 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)346 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)347 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)348=== CONT TestEncodeNixBase32/test_string_hash349=== CONT TestEncodeNixBase32/empty_input350=== CONT TestSetClientTLSErrors/missing_cert_file351--- PASS: TestEncodeNixBase32 (0.00s)352 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)353 --- PASS: TestEncodeNixBase32/empty_input (0.00s)354=== CONT TestSetClientTLSErrors/missing_ca_file355=== CONT TestSetClientTLSErrors/invalid_ca_file356=== CONT TestSetClientTLSErrors/missing_key_file357--- PASS: TestSetClientTLSErrors (0.00s)358 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)359 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)360 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)361 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)362=== CONT TestSetClientTLS/rejects_connection_without_client_cert363--- PASS: TestUploadMultipart_SupersededByPeer (0.00s)364 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)365 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)366=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA367=== CONT TestSetClientTLS/preserves_debug_logging_transport368--- PASS: TestDumpPathWriterError (0.04s)369--- PASS: TestRegisterUploadedObjectReusesConnections (0.04s)3702026/09/20 10:38:08 http: TLS handshake error from 127.0.0.1:54479: remote error: tls: bad certificate371--- PASS: TestSetClientTLS (0.00s)372 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.00s)373 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.00s)374 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.01s)375--- PASS: TestCaseHackSuffix (0.05s)376--- PASS: TestDumpPathSingleFile (0.05s)377--- PASS: TestDumpPathMatchesNix (0.07s)378--- PASS: TestStreamPushBatchesUnderLoad (0.10s)379--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)380PASS381Running server tests...382The files belonging to this database system will be owned by user "_nixbld1".383This user must also own the server process.384385The database cluster will be initialized with locale "C".386The default database encoding has accordingly been set to "SQL_ASCII".387The default text search configuration will be set to "english".388389Data page checksums are enabled.390391creating directory /nix/var/nix/builds/nix-52094-4089225465/postgres73793488/data ... ok392creating subdirectories ... ok393selecting dynamic shared memory implementation ... posix394selecting default "max_connections" ... 100395selecting default "shared_buffers" ... 128MB396selecting default time zone ... UTC397creating configuration files ... ok398running bootstrap script ... ok399performing post-bootstrap initialization ... ok400syncing data to disk ... ok401402initdb: warning: enabling "trust" authentication for local connections403initdb: 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.404405Success. You can now start the database server using:406407 pg_ctl -D /nix/var/nix/builds/nix-52094-4089225465/postgres73793488/data -l logfile start408409/nix/var/nix/builds/nix-52094-4089225465/postgres73793488:5432 - no response4102026-09-20 10:38:09.849 UTC [52136] LOG: starting PostgreSQL 18.6 on aarch64-apple-darwin25.6.0, compiled by clang version 21.1.8, 64-bit4112026-09-20 10:38:09.849 UTC [52136] LOG: listening on Unix socket "/nix/var/nix/builds/nix-52094-4089225465/postgres73793488/.s.PGSQL.5432"4122026-09-20 10:38:09.852 UTC [52143] LOG: database system was shut down at 2026-09-20 10:38:09 UTC4132026-09-20 10:38:09.853 UTC [52136] LOG: database system is ready to accept connections414/nix/var/nix/builds/nix-52094-4089225465/postgres73793488:5432 - accepting connections415=== RUN TestService_AuthMiddleware416=== PAUSE TestService_AuthMiddleware417=== RUN TestService_AuthMiddleware_MTLSProxyHeader418=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader419=== RUN TestService_AuthMiddleware_MTLSBoundSubjects420=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects421=== RUN TestService_ReadAuthMiddleware422=== PAUSE TestService_ReadAuthMiddleware423=== RUN TestService_AuthMiddleware_OIDC424=== PAUSE TestService_AuthMiddleware_OIDC425=== RUN TestService_RequireScope_OIDC426=== PAUSE TestService_RequireScope_OIDC427=== RUN TestService_ReadScope_PublicByDefault428=== PAUSE TestService_ReadScope_PublicByDefault429=== RUN TestCacheConfigHandler430=== PAUSE TestCacheConfigHandler431=== RUN TestCacheStatsHandler432=== PAUSE TestCacheStatsHandler433=== RUN TestClientCADerivations434=== PAUSE TestClientCADerivations435=== RUN TestClientErrorHandling436=== PAUSE TestClientErrorHandling437=== RUN TestClientIntegration438=== PAUSE TestClientIntegration439=== RUN TestClientMultipleUploads440=== PAUSE TestClientMultipleUploads441=== RUN TestClientWithDependencies442=== PAUSE TestClientWithDependencies443=== RUN TestClientSharedPathCommittedMidPush444=== PAUSE TestClientSharedPathCommittedMidPush445=== RUN TestPinProtectsFromGC446=== PAUSE TestPinProtectsFromGC447=== RUN TestResolveDBConnectionString448=== PAUSE TestResolveDBConnectionString449=== RUN TestGCAdvisoryLockBlocksConcurrentRun4502026-09-20 10:38:10.291 UTC [52215] ERROR: relation "goose_db_version" does not exist at character 364512026-09-20 10:38:10.291 UTC [52215] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC4522026/09/20 10:38:10 OK 20241026095416_initial_model.sql (4.84ms)4532026/09/20 10:38:10 OK 20251210153512_drop_unused_gin_index.sql (510.46µs)4542026/09/20 10:38:10 OK 20251218171726_add_pins.sql (969.04µs)4552026/09/20 10:38:10 OK 20260628120000_add_object_size_and_stats.sql (1.04ms)4562026/09/20 10:38:10 OK 20260905000000_add_claims.sql (1.26ms)4572026/09/20 10:38:10 OK 20260920000000_drop_claims.sql (742.38µs)4582026/09/20 10:38:10 goose: successfully migrated database to version: 202609200000004592026/09/20 10:38:10 OK 1_commit_pending_closure.sql (999.67µs)4602026/09/20 10:38:10 OK 2_object_stats_trigger.sql (233.92µs)4612026/09/20 10:38:10 goose: up to current file version: 2462--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.30s)463=== RUN TestGCBugBareHashReferences464=== PAUSE TestGCBugBareHashReferences465=== RUN TestGCMetrics466=== PAUSE TestGCMetrics467=== RUN TestGCTaskStore_StartNew468=== PAUSE TestGCTaskStore_StartNew469=== RUN TestGCTaskStore_DeduplicateSameParams470=== PAUSE TestGCTaskStore_DeduplicateSameParams471=== RUN TestGCTaskStore_ConflictDifferentParams472=== PAUSE TestGCTaskStore_ConflictDifferentParams473=== RUN TestGCTaskStore_GetEmpty474=== PAUSE TestGCTaskStore_GetEmpty475=== RUN TestGCTaskStore_GetReturnsLatest476=== PAUSE TestGCTaskStore_GetReturnsLatest477=== RUN TestGCTaskStore_CompletedAllowsNewTask478=== PAUSE TestGCTaskStore_CompletedAllowsNewTask479=== RUN TestGCTaskStore_PhaseUpdates480=== PAUSE TestGCTaskStore_PhaseUpdates481=== RUN TestGCTaskStore_Fail482=== PAUSE TestGCTaskStore_Fail483=== RUN TestGracefulShutdownDrainsInflight484=== PAUSE TestGracefulShutdownDrainsInflight485=== RUN TestService_healthCheckHandler486=== PAUSE TestService_healthCheckHandler487=== RUN TestService_readinessHandler488=== PAUSE TestService_readinessHandler489=== RUN TestGenerateLandingPage490=== PAUSE TestGenerateLandingPage491=== RUN TestCacheConfigHandlerMaxNarSize492=== PAUSE TestCacheConfigHandlerMaxNarSize493=== RUN TestCreatePendingClosureRejectsOversizedNAR494=== PAUSE TestCreatePendingClosureRejectsOversizedNAR495=== RUN TestNARDeduplicationMetadataUploadBug496=== PAUSE TestNARDeduplicationMetadataUploadBug497=== RUN TestMetricsInventory498=== PAUSE TestMetricsInventory499=== RUN TestService_NativeMTLS500=== PAUSE TestService_NativeMTLS501=== RUN TestServerTLSConfig502=== PAUSE TestServerTLSConfig503=== RUN TestMultipartCleanup504=== PAUSE TestMultipartCleanup505=== RUN TestObjectStatsTrigger506=== PAUSE TestObjectStatsTrigger507=== RUN TestOrphanedObjectsGC508=== PAUSE TestOrphanedObjectsGC509=== RUN TestOrphanedObjectsGCStressTest510=== PAUSE TestOrphanedObjectsGCStressTest511=== RUN TestResurrectedObjectNotDeleted512=== PAUSE TestResurrectedObjectNotDeleted513=== RUN TestParseSingleRange514=== PAUSE TestParseSingleRange515=== RUN TestIsValidCachePath516=== PAUSE TestIsValidCachePath517=== RUN TestReadProxyNarinfo518=== PAUSE TestReadProxyNarinfo519=== RUN TestReadProxyNarinfoAlreadyDecompressed520=== PAUSE TestReadProxyNarinfoAlreadyDecompressed521=== RUN TestReadProxyNarStreaming522=== PAUSE TestReadProxyNarStreaming523=== RUN TestReadProxy404524=== PAUSE TestReadProxy404525=== RUN TestReadProxyInvalidPath526=== PAUSE TestReadProxyInvalidPath527=== RUN TestReadProxyHead528=== PAUSE TestReadProxyHead529=== RUN TestReadProxyConditionalGet530=== PAUSE TestReadProxyConditionalGet531=== RUN TestReadProxyRootRedirectsToIndexHTML532=== PAUSE TestReadProxyRootRedirectsToIndexHTML533=== RUN TestReadProxyDisabled534=== PAUSE TestReadProxyDisabled535=== RUN TestReadRedirectNar536=== PAUSE TestReadRedirectNar537=== RUN TestReadRedirectKeepsNarinfoProxied538=== PAUSE TestReadRedirectKeepsNarinfoProxied539=== RUN TestReadProxyRangeRequest540=== PAUSE TestReadProxyRangeRequest541=== RUN TestReadRedirectUsesPublicS3URL542=== PAUSE TestReadRedirectUsesPublicS3URL543=== RUN TestRedundantMultipartUpload544=== PAUSE TestRedundantMultipartUpload545=== RUN TestCompleteMultipartUpload_ErrorButObjectExists546=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists547=== RUN TestCompletedNarNotReofferedAcrossClosures548=== PAUSE TestCompletedNarNotReofferedAcrossClosures549=== RUN TestPresignedUploadRegisteredBeforeCommit550=== PAUSE TestPresignedUploadRegisteredBeforeCommit551=== RUN TestService_Rustfstest552=== PAUSE TestService_Rustfstest553=== RUN TestParseSize554=== PAUSE TestParseSize555=== RUN TestSkippedUploadsHandler556=== PAUSE TestSkippedUploadsHandler557=== RUN TestSystemdListenerNotActivated558--- PASS: TestSystemdListenerNotActivated (0.00s)559=== RUN TestWatchdogBeatsWhenHealthy560--- PASS: TestWatchdogBeatsWhenHealthy (0.03s)561=== RUN TestWatchdogSkipsWhenUnhealthy5622026/09/20 10:38:10 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5632026/09/20 10:38:10 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5642026/09/20 10:38:10 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5652026/09/20 10:38:10 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5662026/09/20 10:38:10 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5672026/09/20 10:38:10 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5682026/09/20 10:38:10 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5692026/09/20 10:38:10 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5702026/09/20 10:38:10 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5712026/09/20 10:38:10 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"572--- PASS: TestWatchdogSkipsWhenUnhealthy (0.21s)573=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle574=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle575=== RUN TestProxyWriteTimeout576=== PAUSE TestProxyWriteTimeout577=== RUN TestIsValidUploadKey578=== PAUSE TestIsValidUploadKey579=== RUN TestUploadHandlersRejectInvalidKeys580=== PAUSE TestUploadHandlersRejectInvalidKeys581=== RUN TestUploadHandlersRejectOversizedBody582=== PAUSE TestUploadHandlersRejectOversizedBody583=== RUN TestService_cleanupPendingClosuresHandler584=== PAUSE TestService_cleanupPendingClosuresHandler585=== RUN TestService_createPendingClosureHandler586=== PAUSE TestService_createPendingClosureHandler587=== RUN TestService_verifyS3Integrity588=== PAUSE TestService_verifyS3Integrity589=== RUN TestCompleteMultipartUnregistered590=== PAUSE TestCompleteMultipartUnregistered591=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT592=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT593=== CONT TestCompleteMultipartUnregistered594=== CONT TestReadProxyNarinfoAlreadyDecompressed595=== CONT TestParseSingleRange596=== CONT TestCompletedNarNotReofferedAcrossClosures597=== RUN TestParseSingleRange/none598=== CONT TestService_verifyS3Integrity599=== PAUSE TestParseSingleRange/none600=== RUN TestParseSingleRange/unknown_unit601=== PAUSE TestParseSingleRange/unknown_unit602=== RUN TestParseSingleRange/multi-range_ignored603=== PAUSE TestParseSingleRange/multi-range_ignored604=== RUN TestParseSingleRange/malformed_no_dash605=== PAUSE TestParseSingleRange/malformed_no_dash606=== RUN TestParseSingleRange/malformed_both_empty607=== PAUSE TestParseSingleRange/malformed_both_empty608=== RUN TestParseSingleRange/malformed_end_before_start609=== PAUSE TestParseSingleRange/malformed_end_before_start610=== RUN TestParseSingleRange/closed611=== PAUSE TestParseSingleRange/closed612=== RUN TestParseSingleRange/open-ended613=== CONT TestReadProxyDisabled614=== PAUSE TestParseSingleRange/open-ended615=== RUN TestParseSingleRange/end_clamped_to_size616=== PAUSE TestParseSingleRange/end_clamped_to_size617=== RUN TestParseSingleRange/suffix618=== PAUSE TestParseSingleRange/suffix619=== RUN TestParseSingleRange/suffix_exceeds_size620=== PAUSE TestParseSingleRange/suffix_exceeds_size621=== RUN TestParseSingleRange/single_byte622=== PAUSE TestParseSingleRange/single_byte623=== RUN TestParseSingleRange/start_past_EOF624=== PAUSE TestParseSingleRange/start_past_EOF625=== RUN TestParseSingleRange/start_far_past_EOF626=== PAUSE TestParseSingleRange/start_far_past_EOF627=== CONT TestCompleteMultipartUpload_ErrorButObjectExists628=== CONT TestService_AuthMiddleware629=== CONT TestReadProxyNarinfo630=== CONT TestIsValidCachePath631=== RUN TestIsValidCachePath/narinfo632=== CONT TestReadRedirectUsesPublicS3URL633=== PAUSE TestIsValidCachePath/narinfo634=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars635=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars636=== RUN TestIsValidCachePath/nar_zst637=== PAUSE TestIsValidCachePath/nar_zst638=== RUN TestIsValidCachePath/nar_xz639=== PAUSE TestIsValidCachePath/nar_xz640=== RUN TestIsValidCachePath/nar_bz2641=== PAUSE TestIsValidCachePath/nar_bz2642=== RUN TestIsValidCachePath/nar_uncompressed643=== PAUSE TestIsValidCachePath/nar_uncompressed644=== RUN TestIsValidCachePath/ls645=== PAUSE TestIsValidCachePath/ls646=== RUN TestIsValidCachePath/log647=== PAUSE TestIsValidCachePath/log648=== RUN TestIsValidCachePath/realisation649=== PAUSE TestIsValidCachePath/realisation650=== RUN TestIsValidCachePath/nix-cache-info651=== PAUSE TestIsValidCachePath/nix-cache-info652=== RUN TestIsValidCachePath/index.html653=== PAUSE TestIsValidCachePath/index.html654=== RUN TestIsValidCachePath/traversal_parent655=== PAUSE TestIsValidCachePath/traversal_parent656=== RUN TestIsValidCachePath/traversal_in_middle657=== PAUSE TestIsValidCachePath/traversal_in_middle658=== RUN TestIsValidCachePath/invalid_char_e659=== PAUSE TestIsValidCachePath/invalid_char_e660=== RUN TestIsValidCachePath/invalid_char_u661=== PAUSE TestIsValidCachePath/invalid_char_u662=== RUN TestIsValidCachePath/random_path663=== PAUSE TestIsValidCachePath/random_path664=== RUN TestIsValidCachePath/empty665=== PAUSE TestIsValidCachePath/empty666=== RUN TestIsValidCachePath/leading_slash667=== PAUSE TestIsValidCachePath/leading_slash668=== RUN TestIsValidCachePath/wrong_extension669=== PAUSE TestIsValidCachePath/wrong_extension670=== RUN TestIsValidCachePath/short_hash671=== PAUSE TestIsValidCachePath/short_hash672=== CONT TestRedundantMultipartUpload6732026-09-20 10:38:10.906 UTC [52238] ERROR: relation "goose_db_version" does not exist at character 366742026-09-20 10:38:10.906 UTC [52238] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6752026-09-20 10:38:10.938 UTC [52239] ERROR: relation "goose_db_version" does not exist at character 366762026-09-20 10:38:10.938 UTC [52239] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6772026-09-20 10:38:10.945 UTC [52242] ERROR: relation "goose_db_version" does not exist at character 366782026-09-20 10:38:10.945 UTC [52242] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6792026-09-20 10:38:10.945 UTC [52241] ERROR: relation "goose_db_version" does not exist at character 366802026-09-20 10:38:10.945 UTC [52241] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6812026/09/20 10:38:10 OK 20241026095416_initial_model.sql (26.25ms)6822026-09-20 10:38:10.946 UTC [52243] ERROR: relation "goose_db_version" does not exist at character 366832026-09-20 10:38:10.946 UTC [52243] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6842026/09/20 10:38:10 OK 20251210153512_drop_unused_gin_index.sql (3.03ms)6852026-09-20 10:38:10.949 UTC [52247] ERROR: relation "goose_db_version" does not exist at character 366862026-09-20 10:38:10.949 UTC [52247] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6872026-09-20 10:38:10.949 UTC [52248] ERROR: relation "goose_db_version" does not exist at character 366882026-09-20 10:38:10.949 UTC [52248] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6892026-09-20 10:38:10.949 UTC [52246] ERROR: relation "goose_db_version" does not exist at character 366902026-09-20 10:38:10.949 UTC [52246] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6912026-09-20 10:38:10.950 UTC [52245] ERROR: relation "goose_db_version" does not exist at character 366922026-09-20 10:38:10.950 UTC [52245] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6932026/09/20 10:38:10 OK 20251218171726_add_pins.sql (1.39ms)6942026-09-20 10:38:10.951 UTC [52244] ERROR: relation "goose_db_version" does not exist at character 366952026-09-20 10:38:10.951 UTC [52244] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6962026/09/20 10:38:10 OK 20260628120000_add_object_size_and_stats.sql (2.43ms)6972026/09/20 10:38:10 OK 20260905000000_add_claims.sql (3.45ms)6982026/09/20 10:38:10 OK 20241026095416_initial_model.sql (8.77ms)6992026/09/20 10:38:10 OK 20241026095416_initial_model.sql (7.5ms)7002026/09/20 10:38:10 OK 20241026095416_initial_model.sql (7.06ms)7012026/09/20 10:38:10 OK 20251210153512_drop_unused_gin_index.sql (1.44ms)7022026/09/20 10:38:10 OK 20241026095416_initial_model.sql (9ms)7032026/09/20 10:38:10 OK 20251210153512_drop_unused_gin_index.sql (1.02ms)7042026/09/20 10:38:10 OK 20251210153512_drop_unused_gin_index.sql (1.33ms)7052026/09/20 10:38:10 OK 20260920000000_drop_claims.sql (2.01ms)7062026/09/20 10:38:10 goose: successfully migrated database to version: 202609200000007072026/09/20 10:38:10 OK 20241026095416_initial_model.sql (6.76ms)7082026/09/20 10:38:10 OK 20251210153512_drop_unused_gin_index.sql (1.31ms)7092026/09/20 10:38:10 OK 1_commit_pending_closure.sql (1.68ms)7102026/09/20 10:38:10 OK 20241026095416_initial_model.sql (7.38ms)7112026/09/20 10:38:10 OK 20251218171726_add_pins.sql (2.59ms)7122026/09/20 10:38:10 OK 20251210153512_drop_unused_gin_index.sql (1.33ms)7132026/09/20 10:38:10 OK 20251218171726_add_pins.sql (2.24ms)7142026/09/20 10:38:10 OK 2_object_stats_trigger.sql (1.08ms)7152026/09/20 10:38:10 goose: up to current file version: 27162026/09/20 10:38:10 OK 20251218171726_add_pins.sql (3.08ms)7172026/09/20 10:38:10 OK 20241026095416_initial_model.sql (9.05ms)7182026/09/20 10:38:10 OK 20251218171726_add_pins.sql (2.36ms)7192026/09/20 10:38:10 OK 20251210153512_drop_unused_gin_index.sql (1.7ms)7202026/09/20 10:38:10 OK 20241026095416_initial_model.sql (7.24ms)7212026/09/20 10:38:10 OK 20251210153512_drop_unused_gin_index.sql (1.3ms)7222026/09/20 10:38:10 OK 20260628120000_add_object_size_and_stats.sql (2.34ms)7232026/09/20 10:38:10 OK 20251218171726_add_pins.sql (2.58ms)7242026/09/20 10:38:10 OK 20260628120000_add_object_size_and_stats.sql (2.47ms)7252026/09/20 10:38:10 OK 20241026095416_initial_model.sql (7.38ms)7262026/09/20 10:38:10 OK 20260628120000_add_object_size_and_stats.sql (2.17ms)7272026/09/20 10:38:10 OK 20260628120000_add_object_size_and_stats.sql (2.3ms)7282026/09/20 10:38:10 OK 20251210153512_drop_unused_gin_index.sql (1.51ms)7292026/09/20 10:38:10 OK 20251218171726_add_pins.sql (2.13ms)7302026/09/20 10:38:10 OK 20251210153512_drop_unused_gin_index.sql (1.58ms)7312026/09/20 10:38:10 OK 20251218171726_add_pins.sql (3.25ms)7322026/09/20 10:38:10 OK 20260628120000_add_object_size_and_stats.sql (2.58ms)7332026/09/20 10:38:10 OK 20260905000000_add_claims.sql (2.83ms)7342026/09/20 10:38:10 OK 20260905000000_add_claims.sql (3.16ms)7352026/09/20 10:38:10 OK 20260905000000_add_claims.sql (2.62ms)7362026/09/20 10:38:10 OK 20251218171726_add_pins.sql (2.1ms)7372026/09/20 10:38:10 OK 20260628120000_add_object_size_and_stats.sql (1.89ms)7382026/09/20 10:38:10 OK 20251218171726_add_pins.sql (1.8ms)7392026/09/20 10:38:10 OK 20260628120000_add_object_size_and_stats.sql (1.85ms)7402026/09/20 10:38:10 OK 20260920000000_drop_claims.sql (1.44ms)7412026/09/20 10:38:10 goose: successfully migrated database to version: 202609200000007422026/09/20 10:38:10 OK 20260920000000_drop_claims.sql (1.73ms)7432026/09/20 10:38:10 goose: successfully migrated database to version: 202609200000007442026/09/20 10:38:10 OK 20260905000000_add_claims.sql (3.64ms)7452026/09/20 10:38:10 OK 20260905000000_add_claims.sql (2.4ms)7462026/09/20 10:38:10 OK 1_commit_pending_closure.sql (1.1ms)7472026/09/20 10:38:10 OK 1_commit_pending_closure.sql (1.1ms)7482026/09/20 10:38:10 OK 2_object_stats_trigger.sql (225.96µs)7492026/09/20 10:38:10 goose: up to current file version: 27502026/09/20 10:38:10 OK 2_object_stats_trigger.sql (222.17µs)7512026/09/20 10:38:10 goose: up to current file version: 27522026/09/20 10:38:10 OK 20260920000000_drop_claims.sql (6.35ms)7532026/09/20 10:38:10 goose: successfully migrated database to version: 202609200000007542026/09/20 10:38:10 OK 20260920000000_drop_claims.sql (5.35ms)7552026/09/20 10:38:10 goose: successfully migrated database to version: 202609200000007562026/09/20 10:38:10 OK 20260920000000_drop_claims.sql (5.06ms)7572026/09/20 10:38:10 goose: successfully migrated database to version: 202609200000007582026/09/20 10:38:10 OK 20260628120000_add_object_size_and_stats.sql (6.52ms)7592026/09/20 10:38:10 OK 20260628120000_add_object_size_and_stats.sql (7.15ms)7602026/09/20 10:38:10 OK 20260905000000_add_claims.sql (6.59ms)7612026/09/20 10:38:10 OK 1_commit_pending_closure.sql (1.38ms)7622026/09/20 10:38:10 OK 1_commit_pending_closure.sql (881.46µs)7632026/09/20 10:38:10 OK 1_commit_pending_closure.sql (1ms)7642026/09/20 10:38:10 OK 2_object_stats_trigger.sql (236.29µs)7652026/09/20 10:38:10 goose: up to current file version: 27662026/09/20 10:38:10 OK 2_object_stats_trigger.sql (284.67µs)7672026/09/20 10:38:10 goose: up to current file version: 27682026/09/20 10:38:10 OK 2_object_stats_trigger.sql (205.88µs)7692026/09/20 10:38:10 goose: up to current file version: 27702026/09/20 10:38:10 OK 20260905000000_add_claims.sql (11.44ms)7712026/09/20 10:38:10 OK 20260920000000_drop_claims.sql (5.79ms)7722026/09/20 10:38:10 goose: successfully migrated database to version: 202609200000007732026/09/20 10:38:10 OK 20260920000000_drop_claims.sql (1.42ms)7742026/09/20 10:38:10 goose: successfully migrated database to version: 202609200000007752026/09/20 10:38:10 OK 1_commit_pending_closure.sql (708.54µs)7762026/09/20 10:38:10 OK 2_object_stats_trigger.sql (193.63µs)7772026/09/20 10:38:10 goose: up to current file version: 27782026/09/20 10:38:10 OK 1_commit_pending_closure.sql (735.08µs)7792026/09/20 10:38:10 OK 2_object_stats_trigger.sql (190.29µs)7802026/09/20 10:38:10 goose: up to current file version: 27812026/09/20 10:38:10 OK 20260905000000_add_claims.sql (12.99ms)7822026/09/20 10:38:10 OK 20260905000000_add_claims.sql (13.07ms)7832026/09/20 10:38:10 OK 20260920000000_drop_claims.sql (967.33µs)7842026/09/20 10:38:10 goose: successfully migrated database to version: 202609200000007852026/09/20 10:38:10 OK 20260920000000_drop_claims.sql (1.11ms)7862026/09/20 10:38:10 goose: successfully migrated database to version: 202609200000007872026/09/20 10:38:10 OK 1_commit_pending_closure.sql (689.38µs)7882026/09/20 10:38:10 OK 1_commit_pending_closure.sql (747.92µs)7892026/09/20 10:38:10 OK 2_object_stats_trigger.sql (189.33µs)7902026/09/20 10:38:10 goose: up to current file version: 27912026/09/20 10:38:10 OK 2_object_stats_trigger.sql (179.42µs)7922026/09/20 10:38:10 goose: up to current file version: 27932026/09/20 10:38:11 INFO Received complete multipart upload request method=POST path=/api/multipart/complete7942026/09/20 10:38:11 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst795--- PASS: TestCompleteMultipartUnregistered (0.44s)796=== CONT TestProxyWriteTimeout797=== RUN TestProxyWriteTimeout/narinfo798=== PAUSE TestProxyWriteTimeout/narinfo799=== RUN TestProxyWriteTimeout/1_GiB_nar800=== PAUSE TestProxyWriteTimeout/1_GiB_nar801=== RUN TestProxyWriteTimeout/10_GiB_nar802=== PAUSE TestProxyWriteTimeout/10_GiB_nar803=== RUN TestProxyWriteTimeout/unknown_size804=== PAUSE TestProxyWriteTimeout/unknown_size805=== CONT TestService_createPendingClosureHandler8062026/09/20 10:38:11 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"807--- PASS: TestService_AuthMiddleware (0.57s)808=== CONT TestService_cleanupPendingClosuresHandler8092026/09/20 10:38:11 INFO Received uploads request method=POST path=/api/pending_closures8102026/09/20 10:38:11 INFO Received uploads request method=POST path=/api/pending_closures811--- PASS: TestReadProxyNarinfoAlreadyDecompressed (0.87s)812=== CONT TestUploadHandlersRejectOversizedBody813=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart814=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart815=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts816=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts817=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure818=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure819=== CONT TestUploadHandlersRejectInvalidKeys820=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info821=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info822=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal823=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal824=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key825=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key826=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key827=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key828=== CONT TestIsValidUploadKey829=== RUN TestIsValidUploadKey/narinfo830=== PAUSE TestIsValidUploadKey/narinfo831=== RUN TestIsValidUploadKey/nar_zst832=== PAUSE TestIsValidUploadKey/nar_zst833=== RUN TestIsValidUploadKey/nar_xz834=== PAUSE TestIsValidUploadKey/nar_xz835=== RUN TestIsValidUploadKey/nar_plain836=== PAUSE TestIsValidUploadKey/nar_plain837=== RUN TestIsValidUploadKey/listing838=== PAUSE TestIsValidUploadKey/listing839=== RUN TestIsValidUploadKey/build_log840=== PAUSE TestIsValidUploadKey/build_log841=== RUN TestIsValidUploadKey/build_log_home-manager_file842=== PAUSE TestIsValidUploadKey/build_log_home-manager_file843=== RUN TestIsValidUploadKey/build_log_plus_in_name844=== PAUSE TestIsValidUploadKey/build_log_plus_in_name845=== RUN TestIsValidUploadKey/build_log_question_mark846=== PAUSE TestIsValidUploadKey/build_log_question_mark847=== RUN TestIsValidUploadKey/build_log_equals848=== PAUSE TestIsValidUploadKey/build_log_equals849=== RUN TestIsValidUploadKey/realisation850=== PAUSE TestIsValidUploadKey/realisation851=== RUN TestIsValidUploadKey/realisation_plus_in_output852=== PAUSE TestIsValidUploadKey/realisation_plus_in_output853=== RUN TestIsValidUploadKey/nix-cache-info854=== PAUSE TestIsValidUploadKey/nix-cache-info855=== RUN TestIsValidUploadKey/index.html856=== PAUSE TestIsValidUploadKey/index.html857=== RUN TestIsValidUploadKey/narinfo_key,_nar_type858=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type859=== RUN TestIsValidUploadKey/nar_key,_narinfo_type860=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type861=== RUN TestIsValidUploadKey/listing_key,_narinfo_type862=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type863=== RUN TestIsValidUploadKey/traversal864=== PAUSE TestIsValidUploadKey/traversal865=== RUN TestIsValidUploadKey/traversal_nar866=== PAUSE TestIsValidUploadKey/traversal_nar867=== RUN TestIsValidUploadKey/absolute868=== PAUSE TestIsValidUploadKey/absolute869=== RUN TestIsValidUploadKey/empty_key870=== PAUSE TestIsValidUploadKey/empty_key871=== RUN TestIsValidUploadKey/unknown_type872=== PAUSE TestIsValidUploadKey/unknown_type873=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT8742026/09/20 10:38:11 INFO Received uploads request method=POST path=/api/pending_closures8752026-09-20 10:38:11.637 UTC [52256] ERROR: relation "goose_db_version" does not exist at character 368762026-09-20 10:38:11.637 UTC [52256] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8772026/09/20 10:38:11 OK 20241026095416_initial_model.sql (124.96ms)8782026/09/20 10:38:11 OK 20251210153512_drop_unused_gin_index.sql (9.12ms)8792026/09/20 10:38:11 OK 20251218171726_add_pins.sql (23.07ms)8802026/09/20 10:38:11 OK 20260628120000_add_object_size_and_stats.sql (23.47ms)8812026/09/20 10:38:11 INFO Received uploads request method=POST path=/api/pending_closures8822026/09/20 10:38:11 OK 20260905000000_add_claims.sql (26.03ms)8832026-09-20 10:38:11.848 UTC [52257] ERROR: relation "goose_db_version" does not exist at character 368842026-09-20 10:38:11.848 UTC [52257] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8852026/09/20 10:38:11 OK 20260920000000_drop_claims.sql (21.9ms)8862026/09/20 10:38:11 goose: successfully migrated database to version: 202609200000008872026/09/20 10:38:11 OK 1_commit_pending_closure.sql (2.03ms)8882026/09/20 10:38:11 OK 2_object_stats_trigger.sql (357.88µs)8892026/09/20 10:38:11 goose: up to current file version: 28902026/09/20 10:38:12 OK 20241026095416_initial_model.sql (154.66ms)8912026/09/20 10:38:12 OK 20251210153512_drop_unused_gin_index.sql (15.3ms)8922026/09/20 10:38:12 OK 20251218171726_add_pins.sql (20.19ms)893--- PASS: TestReadProxyNarinfo (1.52s)894=== CONT TestReadProxyHead8952026/09/20 10:38:12 OK 20260628120000_add_object_size_and_stats.sql (27.13ms)8962026/09/20 10:38:12 OK 20260905000000_add_claims.sql (24.48ms)8972026/09/20 10:38:12 OK 20260920000000_drop_claims.sql (61.19ms)8982026/09/20 10:38:12 goose: successfully migrated database to version: 202609200000008992026/09/20 10:38:12 OK 1_commit_pending_closure.sql (2.16ms)9002026/09/20 10:38:12 OK 2_object_stats_trigger.sql (488.5µs)9012026/09/20 10:38:12 goose: up to current file version: 2902--- PASS: TestReadRedirectUsesPublicS3URL (1.77s)903=== CONT TestReadProxyRootRedirectsToIndexHTML9042026/09/20 10:38:12 INFO Received uploads request method=POST path=/api/pending_closures9052026-09-20 10:38:12.608 UTC [52262] ERROR: relation "goose_db_version" does not exist at character 369062026-09-20 10:38:12.608 UTC [52262] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9072026/09/20 10:38:12 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9082026/09/20 10:38:12 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=OWQyN2E2YWMtZWU3ZS00M2JkLTljNmUtN2UwOWQ4ZTJkYjhiLjMzYThlNDI1LTY3NmItNGFiNi05Y2NjLWZhNjRmMGJhM2Q3ZHgxNzg5OTAwNjkxMzAzNDY1MDAw parts=12909--- PASS: TestRedundantMultipartUpload (2.18s)910=== CONT TestReadProxyConditionalGet9112026/09/20 10:38:12 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9122026/09/20 10:38:12 OK 20241026095416_initial_model.sql (202.51ms)9132026/09/20 10:38:12 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=OWQyN2E2YWMtZWU3ZS00M2JkLTljNmUtN2UwOWQ4ZTJkYjhiLmQ5Yjc0NzA3LTg4NGEtNDA3ZS1iN2JmLWMzMmI2ZDJmN2NlM3gxNzg5OTAwNjkyNjAwMjc1MDAw9142026/09/20 10:38:12 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=OWQyN2E2YWMtZWU3ZS00M2JkLTljNmUtN2UwOWQ4ZTJkYjhiLmQ5Yjc0NzA3LTg4NGEtNDA3ZS1iN2JmLWMzMmI2ZDJmN2NlM3gxNzg5OTAwNjkyNjAwMjc1MDAw parts=1915--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (2.29s)916=== CONT TestGCTaskStore_ConflictDifferentParams917--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)918=== CONT TestResurrectedObjectNotDeleted9192026/09/20 10:38:12 OK 20251210153512_drop_unused_gin_index.sql (8.94ms)9202026/09/20 10:38:12 OK 20251218171726_add_pins.sql (12.19ms)921--- PASS: TestReadProxyDisabled (2.31s)922=== CONT TestOrphanedObjectsGCStressTest9232026/09/20 10:38:12 OK 20260628120000_add_object_size_and_stats.sql (6.98ms)9242026/09/20 10:38:12 OK 20260905000000_add_claims.sql (59.06ms)9252026/09/20 10:38:12 OK 20260920000000_drop_claims.sql (21.92ms)9262026/09/20 10:38:12 goose: successfully migrated database to version: 202609200000009272026/09/20 10:38:12 OK 1_commit_pending_closure.sql (2.9ms)9282026/09/20 10:38:12 OK 2_object_stats_trigger.sql (477.25µs)9292026/09/20 10:38:12 goose: up to current file version: 29302026/09/20 10:38:13 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9312026/09/20 10:38:13 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9322026/09/20 10:38:13 INFO Received uploads request method=POST path=/api/pending_closures9332026/09/20 10:38:13 INFO Received uploads request method=POST path=/api/pending_closures9342026/09/20 10:38:13 INFO Received uploads request method=POST path=/api/pending_closures9352026/09/20 10:38:13 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=OWQyN2E2YWMtZWU3ZS00M2JkLTljNmUtN2UwOWQ4ZTJkYjhiLjA3ODA2MGU2LTZlYzYtNGNkZS1hY2EyLTY1MjI5ZjM1ZmVjZngxNzg5OTAwNjkxNjQwNjkwMDAw parts=129362026/09/20 10:38:13 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=OWQyN2E2YWMtZWU3ZS00M2JkLTljNmUtN2UwOWQ4ZTJkYjhiLmI4MWJjOGRjLWEzYjYtNDg5Zi1hMGM2LTk2MDhiMDI3NjQ4ZngxNzg5OTAwNjkxODY1MTg3MDAw parts=109372026/09/20 10:38:13 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete9382026/09/20 10:38:13 INFO Received uploads request method=POST path=/api/pending_closures9392026/09/20 10:38:13 INFO Completed upload id=1940--- PASS: TestCompletedNarNotReofferedAcrossClosures (2.58s)941=== CONT TestOrphanedObjectsGC9422026/09/20 10:38:13 INFO Received uploads request method=POST path=/api/pending_closures9432026/09/20 10:38:13 INFO Received uploads request method=POST path=/api/pending_closures9442026/09/20 10:38:13 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo9452026/09/20 10:38:13 WARN Found objects in DB but missing from S3, will re-upload count=1946--- PASS: TestService_verifyS3Integrity (2.59s)947=== CONT TestObjectStatsTrigger9482026-09-20 10:38:13.245 UTC [52273] ERROR: relation "goose_db_version" does not exist at character 369492026-09-20 10:38:13.245 UTC [52273] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9502026/09/20 10:38:13 INFO Received cleanup request method=DELETE path=/api/pending_closures9512026/09/20 10:38:13 INFO Aborted multipart uploads count=09522026/09/20 10:38:13 INFO Received uploads request method=POST path=/api/pending_closures9532026/09/20 10:38:13 OK 20241026095416_initial_model.sql (126.69ms)9542026/09/20 10:38:13 INFO Received cleanup request method=DELETE path=/api/pending_closures9552026/09/20 10:38:13 INFO Aborted multipart uploads count=19562026/09/20 10:38:13 OK 20251210153512_drop_unused_gin_index.sql (6.78ms)9572026/09/20 10:38:13 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete9582026-09-20 10:38:13.447 UTC [52257] ERROR: Closure does not exist: id=19592026-09-20 10:38:13.447 UTC [52257] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 16 at RAISE9602026-09-20 10:38:13.447 UTC [52257] STATEMENT: -- name: CommitPendingClosure :exec961 SELECT commit_pending_closure($1::bigint)962 963--- PASS: TestService_cleanupPendingClosuresHandler (2.28s)964=== CONT TestMultipartCleanup9652026/09/20 10:38:13 OK 20251218171726_add_pins.sql (16.72ms)9662026/09/20 10:38:13 OK 20260628120000_add_object_size_and_stats.sql (41.33ms)9672026/09/20 10:38:13 OK 20260905000000_add_claims.sql (31.23ms)9682026/09/20 10:38:13 OK 20260920000000_drop_claims.sql (18.45ms)9692026/09/20 10:38:13 goose: successfully migrated database to version: 202609200000009702026/09/20 10:38:13 OK 1_commit_pending_closure.sql (2.12ms)9712026/09/20 10:38:13 OK 2_object_stats_trigger.sql (371.92µs)9722026/09/20 10:38:13 goose: up to current file version: 29732026/09/20 10:38:13 INFO Received uploads request method=POST path=/api/pending_closures974--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (2.08s)975=== CONT TestServerTLSConfig976=== RUN TestServerTLSConfig/no_client_CA977=== PAUSE TestServerTLSConfig/no_client_CA978=== RUN TestServerTLSConfig/missing_CA_file979=== PAUSE TestServerTLSConfig/missing_CA_file980=== RUN TestServerTLSConfig/not_a_PEM_file981=== PAUSE TestServerTLSConfig/not_a_PEM_file982=== CONT TestService_NativeMTLS9832026-09-20 10:38:13.843 UTC [52278] ERROR: relation "goose_db_version" does not exist at character 369842026-09-20 10:38:13.843 UTC [52278] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC985--- PASS: TestReadProxyHead (1.75s)986=== CONT TestMetricsInventory9872026/09/20 10:38:14 OK 20241026095416_initial_model.sql (131.59ms)9882026/09/20 10:38:14 OK 20251210153512_drop_unused_gin_index.sql (11.19ms)9892026/09/20 10:38:14 OK 20251218171726_add_pins.sql (19.2ms)9902026/09/20 10:38:14 OK 20260628120000_add_object_size_and_stats.sql (32.95ms)9912026/09/20 10:38:14 OK 20260905000000_add_claims.sql (42.53ms)9922026-09-20 10:38:14.166 UTC [52284] ERROR: relation "goose_db_version" does not exist at character 369932026-09-20 10:38:14.166 UTC [52284] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9942026/09/20 10:38:14 OK 20260920000000_drop_claims.sql (9.61ms)9952026/09/20 10:38:14 goose: successfully migrated database to version: 202609200000009962026/09/20 10:38:14 OK 1_commit_pending_closure.sql (2.79ms)9972026/09/20 10:38:14 OK 2_object_stats_trigger.sql (526.13µs)9982026/09/20 10:38:14 goose: up to current file version: 29992026-09-20 10:38:14.272 UTC [52285] ERROR: relation "goose_db_version" does not exist at character 3610002026-09-20 10:38:14.272 UTC [52285] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10012026/09/20 10:38:14 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10022026/09/20 10:38:14 OK 20241026095416_initial_model.sql (126.33ms)10032026/09/20 10:38:14 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=OWQyN2E2YWMtZWU3ZS00M2JkLTljNmUtN2UwOWQ4ZTJkYjhiLmNhYjg2MGQxLWQ1MjQtNDlhNi05NmU1LWZhMzg3MzUyY2Y5YXgxNzg5OTAwNjkzMTg1MjQ1MDAw parts=1010042026/09/20 10:38:14 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete10052026/09/20 10:38:14 OK 20251210153512_drop_unused_gin_index.sql (2.58ms)10062026/09/20 10:38:14 INFO Completed upload id=110072026/09/20 10:38:14 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000010082026/09/20 10:38:14 INFO Received uploads request method=POST path=/api/pending_closures10092026/09/20 10:38:14 INFO Starting cleanup of old closures method=DELETE path=/api/closures10102026/09/20 10:38:14 INFO Aborted multipart uploads count=010112026/09/20 10:38:14 OK 20251218171726_add_pins.sql (25.4ms)10122026/09/20 10:38:14 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=010132026/09/20 10:38:14 INFO Vacuumed table table=pending_closures10142026/09/20 10:38:14 OK 20260628120000_add_object_size_and_stats.sql (21.1ms)10152026/09/20 10:38:14 INFO Vacuumed table table=pending_objects10162026-09-20 10:38:14.414 UTC [52287] ERROR: relation "goose_db_version" does not exist at character 3610172026-09-20 10:38:14.414 UTC [52287] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10182026/09/20 10:38:14 OK 20260905000000_add_claims.sql (38.57ms)10192026/09/20 10:38:14 INFO Vacuumed table table=multipart_uploads10202026/09/20 10:38:14 OK 20260920000000_drop_claims.sql (4.49ms)10212026/09/20 10:38:14 goose: successfully migrated database to version: 2026092000000010222026/09/20 10:38:14 INFO Vacuumed table table=closures10232026/09/20 10:38:14 OK 20241026095416_initial_model.sql (93.97ms)10242026/09/20 10:38:14 OK 1_commit_pending_closure.sql (3.76ms)10252026/09/20 10:38:14 OK 20251210153512_drop_unused_gin_index.sql (924.54µs)1026--- PASS: TestReadProxyRootRedirectsToIndexHTML (2.06s)1027=== CONT TestNARDeduplicationMetadataUploadBug10282026/09/20 10:38:14 INFO Vacuumed table table=objects10292026/09/20 10:38:14 OK 2_object_stats_trigger.sql (901.71µs)10302026/09/20 10:38:14 goose: up to current file version: 210312026/09/20 10:38:14 OK 20251218171726_add_pins.sql (3.36ms)10322026/09/20 10:38:14 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001033--- PASS: TestService_createPendingClosureHandler (3.41s)1034=== CONT TestCreatePendingClosureRejectsOversizedNAR10352026/09/20 10:38:14 INFO Received uploads request method=POST path=/api/pending_closures1036--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)1037=== CONT TestCacheConfigHandlerMaxNarSize1038--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)1039=== CONT TestGenerateLandingPage1040--- PASS: TestGenerateLandingPage (0.00s)1041=== CONT TestService_readinessHandler10422026/09/20 10:38:14 OK 20260628120000_add_object_size_and_stats.sql (24.91ms)10432026/09/20 10:38:14 OK 20260905000000_add_claims.sql (23.86ms)10442026/09/20 10:38:14 OK 20260920000000_drop_claims.sql (6.06ms)10452026/09/20 10:38:14 goose: successfully migrated database to version: 2026092000000010462026-09-20 10:38:14.491 UTC [52292] ERROR: relation "goose_db_version" does not exist at character 3610472026-09-20 10:38:14.491 UTC [52292] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10482026/09/20 10:38:14 OK 1_commit_pending_closure.sql (21.53ms)10492026/09/20 10:38:14 OK 2_object_stats_trigger.sql (411.33µs)10502026/09/20 10:38:14 goose: up to current file version: 210512026/09/20 10:38:14 OK 20241026095416_initial_model.sql (82.12ms)10522026/09/20 10:38:14 OK 20251210153512_drop_unused_gin_index.sql (3.88ms)10532026-09-20 10:38:14.530 UTC [52293] ERROR: relation "goose_db_version" does not exist at character 3610542026-09-20 10:38:14.530 UTC [52293] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10552026/09/20 10:38:14 OK 20251218171726_add_pins.sql (8.86ms)10562026/09/20 10:38:14 OK 20260628120000_add_object_size_and_stats.sql (13.7ms)10572026/09/20 10:38:14 OK 20260905000000_add_claims.sql (21.69ms)10582026/09/20 10:38:14 OK 20260920000000_drop_claims.sql (21.88ms)10592026/09/20 10:38:14 goose: successfully migrated database to version: 2026092000000010602026/09/20 10:38:14 OK 1_commit_pending_closure.sql (1.46ms)10612026/09/20 10:38:14 OK 2_object_stats_trigger.sql (326.71µs)10622026/09/20 10:38:14 goose: up to current file version: 210632026/09/20 10:38:14 OK 20241026095416_initial_model.sql (81.76ms)10642026/09/20 10:38:14 OK 20251210153512_drop_unused_gin_index.sql (8.17ms)10652026/09/20 10:38:14 OK 20251218171726_add_pins.sql (13.66ms)10662026/09/20 10:38:14 OK 20241026095416_initial_model.sql (84.86ms)10672026/09/20 10:38:14 OK 20251210153512_drop_unused_gin_index.sql (836.83µs)1068--- PASS: TestReadProxyConditionalGet (1.86s)1069=== CONT TestService_healthCheckHandler10702026/09/20 10:38:14 OK 20251218171726_add_pins.sql (11.48ms)10712026/09/20 10:38:14 OK 20260628120000_add_object_size_and_stats.sql (20.86ms)10722026/09/20 10:38:14 OK 20260628120000_add_object_size_and_stats.sql (17.4ms)10732026/09/20 10:38:14 OK 20260905000000_add_claims.sql (17.25ms)10742026/09/20 10:38:14 OK 20260920000000_drop_claims.sql (2.05ms)10752026/09/20 10:38:14 goose: successfully migrated database to version: 2026092000000010762026/09/20 10:38:14 OK 1_commit_pending_closure.sql (1.46ms)10772026/09/20 10:38:14 OK 2_object_stats_trigger.sql (334.71µs)10782026/09/20 10:38:14 goose: up to current file version: 210792026/09/20 10:38:14 OK 20260905000000_add_claims.sql (18.03ms)10802026/09/20 10:38:14 OK 20260920000000_drop_claims.sql (9.55ms)10812026/09/20 10:38:14 goose: successfully migrated database to version: 2026092000000010822026/09/20 10:38:14 OK 1_commit_pending_closure.sql (1.3ms)10832026/09/20 10:38:14 OK 2_object_stats_trigger.sql (336.33µs)10842026/09/20 10:38:14 goose: up to current file version: 210852026-09-20 10:38:14.701 UTC [52296] ERROR: relation "goose_db_version" does not exist at character 3610862026-09-20 10:38:14.701 UTC [52296] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10872026/09/20 10:38:14 OK 20241026095416_initial_model.sql (91.08ms)10882026/09/20 10:38:14 OK 20251210153512_drop_unused_gin_index.sql (4.78ms)10892026/09/20 10:38:14 OK 20251218171726_add_pins.sql (5.31ms)10902026-09-20 10:38:14.844 UTC [52297] ERROR: relation "goose_db_version" does not exist at character 3610912026-09-20 10:38:14.844 UTC [52297] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10922026/09/20 10:38:14 OK 20260628120000_add_object_size_and_stats.sql (23.61ms)10932026/09/20 10:38:14 OK 20260905000000_add_claims.sql (18.68ms)10942026/09/20 10:38:14 OK 20260920000000_drop_claims.sql (18.43ms)10952026/09/20 10:38:14 goose: successfully migrated database to version: 2026092000000010962026/09/20 10:38:14 OK 1_commit_pending_closure.sql (4.06ms)10972026/09/20 10:38:14 OK 2_object_stats_trigger.sql (498.13µs)10982026/09/20 10:38:14 goose: up to current file version: 210992026-09-20 10:38:14.915 UTC [52298] ERROR: relation "goose_db_version" does not exist at character 3611002026-09-20 10:38:14.915 UTC [52298] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11012026/09/20 10:38:14 OK 20241026095416_initial_model.sql (74.39ms)11022026/09/20 10:38:14 OK 20251210153512_drop_unused_gin_index.sql (12.89ms)11032026/09/20 10:38:14 OK 20251218171726_add_pins.sql (17.76ms)11042026/09/20 10:38:14 OK 20260628120000_add_object_size_and_stats.sql (24.56ms)11052026/09/20 10:38:15 OK 20260905000000_add_claims.sql (12.88ms)11062026/09/20 10:38:15 OK 20241026095416_initial_model.sql (68.39ms)11072026/09/20 10:38:15 OK 20251210153512_drop_unused_gin_index.sql (1.51ms)11082026/09/20 10:38:15 OK 20260920000000_drop_claims.sql (3.17ms)11092026/09/20 10:38:15 goose: successfully migrated database to version: 2026092000000011102026/09/20 10:38:15 OK 1_commit_pending_closure.sql (2.49ms)11112026/09/20 10:38:15 OK 2_object_stats_trigger.sql (658.63µs)11122026/09/20 10:38:15 goose: up to current file version: 211132026/09/20 10:38:15 OK 20251218171726_add_pins.sql (11.31ms)11142026/09/20 10:38:15 OK 20260628120000_add_object_size_and_stats.sql (14.37ms)11152026/09/20 10:38:15 OK 20260905000000_add_claims.sql (9.17ms)11162026/09/20 10:38:15 OK 20260920000000_drop_claims.sql (8.1ms)11172026/09/20 10:38:15 goose: successfully migrated database to version: 2026092000000011182026/09/20 10:38:15 OK 1_commit_pending_closure.sql (1.99ms)11192026/09/20 10:38:15 OK 2_object_stats_trigger.sql (453.08µs)11202026/09/20 10:38:15 goose: up to current file version: 21121--- PASS: TestResurrectedObjectNotDeleted (2.17s)1122=== CONT TestGracefulShutdownDrainsInflight11232026/09/20 10:38:15 INFO Starting HTTP server address=127.0.0.1:5458311242026/09/20 10:38:15 INFO Shutdown signal received, draining in-flight requests timeout=10s1125--- PASS: TestGracefulShutdownDrainsInflight (0.07s)1126=== CONT TestGCTaskStore_Fail1127--- PASS: TestGCTaskStore_Fail (0.00s)1128=== CONT TestGCTaskStore_PhaseUpdates1129--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)1130=== CONT TestGCTaskStore_CompletedAllowsNewTask1131--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)1132=== CONT TestGCTaskStore_GetReturnsLatest1133--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)1134=== CONT TestGCTaskStore_GetEmpty1135--- PASS: TestGCTaskStore_GetEmpty (0.00s)1136=== CONT TestClientErrorHandling1137=== RUN TestClientErrorHandling/InvalidStorePath1138=== PAUSE TestClientErrorHandling/InvalidStorePath1139=== RUN TestClientErrorHandling/InvalidAuthToken1140=== PAUSE TestClientErrorHandling/InvalidAuthToken1141=== RUN TestClientErrorHandling/ServerNotAvailable1142=== PAUSE TestClientErrorHandling/ServerNotAvailable1143=== CONT TestGCTaskStore_DeduplicateSameParams1144--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)1145=== CONT TestGCTaskStore_StartNew1146--- PASS: TestGCTaskStore_StartNew (0.00s)1147=== CONT TestGCMetrics1148--- PASS: TestObjectStatsTrigger (2.01s)1149=== CONT TestGCBugBareHashReferences11502026-09-20 10:38:15.283 UTC [52303] ERROR: relation "goose_db_version" does not exist at character 3611512026-09-20 10:38:15.283 UTC [52303] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11522026-09-20 10:38:15.289 UTC [52304] ERROR: relation "goose_db_version" does not exist at character 3611532026-09-20 10:38:15.289 UTC [52304] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11542026/09/20 10:38:15 OK 20241026095416_initial_model.sql (67.05ms)11552026/09/20 10:38:15 OK 20241026095416_initial_model.sql (74.3ms)11562026/09/20 10:38:15 OK 20251210153512_drop_unused_gin_index.sql (6.81ms)11572026/09/20 10:38:15 OK 20251210153512_drop_unused_gin_index.sql (1.25ms)11582026/09/20 10:38:15 OK 20251218171726_add_pins.sql (2.65ms)11592026/09/20 10:38:15 OK 20251218171726_add_pins.sql (10.95ms)11602026/09/20 10:38:15 OK 20260628120000_add_object_size_and_stats.sql (19.25ms)11612026/09/20 10:38:15 OK 20260628120000_add_object_size_and_stats.sql (16.55ms)11622026/09/20 10:38:15 OK 20260905000000_add_claims.sql (11.87ms)11632026/09/20 10:38:15 OK 20260905000000_add_claims.sql (18.72ms)11642026/09/20 10:38:15 OK 20260920000000_drop_claims.sql (14.04ms)11652026/09/20 10:38:15 goose: successfully migrated database to version: 2026092000000011662026/09/20 10:38:15 OK 20260920000000_drop_claims.sql (13.91ms)11672026/09/20 10:38:15 goose: successfully migrated database to version: 2026092000000011682026-09-20 10:38:15.444 UTC [52305] ERROR: relation "goose_db_version" does not exist at character 3611692026-09-20 10:38:15.444 UTC [52305] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11702026/09/20 10:38:15 OK 1_commit_pending_closure.sql (2.24ms)11712026/09/20 10:38:15 OK 1_commit_pending_closure.sql (2.15ms)11722026/09/20 10:38:15 OK 2_object_stats_trigger.sql (397.75µs)11732026/09/20 10:38:15 goose: up to current file version: 211742026/09/20 10:38:15 OK 2_object_stats_trigger.sql (416.29µs)11752026/09/20 10:38:15 goose: up to current file version: 211762026/09/20 10:38:15 INFO Received uploads request method=POST path=/api/pending_closures11772026/09/20 10:38:15 OK 20241026095416_initial_model.sql (50.48ms)11782026/09/20 10:38:15 OK 20251210153512_drop_unused_gin_index.sql (7.22ms)11792026/09/20 10:38:15 OK 20251218171726_add_pins.sql (18.82ms)11802026/09/20 10:38:15 OK 20260628120000_add_object_size_and_stats.sql (8.58ms)11812026/09/20 10:38:15 OK 20260905000000_add_claims.sql (13.99ms)11822026/09/20 10:38:15 OK 20260920000000_drop_claims.sql (14.12ms)11832026/09/20 10:38:15 goose: successfully migrated database to version: 2026092000000011842026/09/20 10:38:15 OK 1_commit_pending_closure.sql (2.07ms)11852026/09/20 10:38:15 OK 2_object_stats_trigger.sql (424.17µs)11862026/09/20 10:38:15 goose: up to current file version: 211872026/09/20 10:38:15 INFO Received cleanup request method=DELETE path=/api/pending_closures11882026/09/20 10:38:15 INFO Aborted multipart uploads count=11189--- PASS: TestMultipartCleanup (2.22s)1190=== CONT TestResolveDBConnectionString1191=== RUN TestResolveDBConnectionString/flag_wins1192=== PAUSE TestResolveDBConnectionString/flag_wins1193=== RUN TestResolveDBConnectionString/file_when_flag_empty1194=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1195=== RUN TestResolveDBConnectionString/missing_file_is_an_error1196=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1197=== RUN TestResolveDBConnectionString/PGHOST_allows_empty1198=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1199=== RUN TestResolveDBConnectionString/nothing_configured1200=== PAUSE TestResolveDBConnectionString/nothing_configured1201=== CONT TestPinProtectsFromGC12022026/09/20 10:38:15 WARN mTLS auth: subject not in bound subjects subject="CN=reader"12032026/09/20 10:38:15 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1204--- PASS: TestService_NativeMTLS (2.01s)1205=== CONT TestClientSharedPathCommittedMidPush1206=== NAME TestOrphanedObjectsGC1207 orphaned_objects_gc_test.go:290: GC Test Summary:1208 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A1209 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B1210 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)1211 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)1212 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects1213--- PASS: TestOrphanedObjectsGC (2.60s)1214=== CONT TestClientWithDependencies1215--- PASS: TestMetricsInventory (2.02s)1216=== CONT TestClientMultipleUploads12172026-09-20 10:38:15.925 UTC [52313] ERROR: relation "goose_db_version" does not exist at character 3612182026-09-20 10:38:15.925 UTC [52313] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12192026-09-20 10:38:15.926 UTC [52314] ERROR: relation "goose_db_version" does not exist at character 3612202026-09-20 10:38:15.926 UTC [52314] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12212026/09/20 10:38:16 OK 20241026095416_initial_model.sql (95.78ms)12222026/09/20 10:38:16 OK 20241026095416_initial_model.sql (95.79ms)12232026/09/20 10:38:16 OK 20251210153512_drop_unused_gin_index.sql (1.2ms)12242026/09/20 10:38:16 OK 20251210153512_drop_unused_gin_index.sql (1.17ms)12252026/09/20 10:38:16 OK 20251218171726_add_pins.sql (18.28ms)12262026/09/20 10:38:16 OK 20251218171726_add_pins.sql (18.61ms)12272026/09/20 10:38:16 OK 20260628120000_add_object_size_and_stats.sql (15.48ms)12282026/09/20 10:38:16 OK 20260628120000_add_object_size_and_stats.sql (16.2ms)12292026/09/20 10:38:16 OK 20260905000000_add_claims.sql (3.7ms)12302026/09/20 10:38:16 OK 20260920000000_drop_claims.sql (16.85ms)12312026/09/20 10:38:16 goose: successfully migrated database to version: 2026092000000012322026/09/20 10:38:16 OK 20260905000000_add_claims.sql (20.21ms)12332026/09/20 10:38:16 OK 1_commit_pending_closure.sql (1.89ms)12342026/09/20 10:38:16 OK 2_object_stats_trigger.sql (422.33µs)12352026/09/20 10:38:16 goose: up to current file version: 212362026/09/20 10:38:16 OK 20260920000000_drop_claims.sql (10.1ms)12372026/09/20 10:38:16 goose: successfully migrated database to version: 2026092000000012382026/09/20 10:38:16 OK 1_commit_pending_closure.sql (1.33ms)12392026/09/20 10:38:16 OK 2_object_stats_trigger.sql (306.46µs)12402026/09/20 10:38:16 goose: up to current file version: 21241=== NAME TestNARDeduplicationMetadataUploadBug1242 metadata_upload_test.go:48: First store path: /nix/var/nix/builds/nix-52094-4089225465/TestNARDeduplicationMetadataUploadBug3543097603/001/store/550ih97mdzffp9fpkw0w4h35i9q08cqn-file1.txt12432026/09/20 10:38:16 WARN readiness check failed error="closed pool"1244--- PASS: TestService_readinessHandler (1.78s)1245=== CONT TestClientIntegration12462026/09/20 10:38:16 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"12472026/09/20 10:38:16 INFO Received uploads request method=POST path=/api/pending_closures12482026/09/20 10:38:16 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)12492026/09/20 10:38:16 INFO Uploading 550ih97mdzffp9fpkw0w4h35i9q08cqn-file1.txt (160B)12502026/09/20 10:38:16 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"12512026/09/20 10:38:16 WARN Failed to register uploaded object key=550ih97mdzffp9fpkw0w4h35i9q08cqn.ls error="server returned 404: 404 page not found\n"12522026/09/20 10:38:16 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign12532026/09/20 10:38:16 INFO Signed narinfos id=1 count=112542026/09/20 10:38:16 INFO Uploading 1 narinfos12552026/09/20 10:38:16 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete12562026/09/20 10:38:16 WARN Failed to register uploaded object key=550ih97mdzffp9fpkw0w4h35i9q08cqn.narinfo error="server returned 404: 404 page not found\n"12572026/09/20 10:38:16 INFO Completed upload id=112582026/09/20 10:38:16 INFO Upload complete. (192ms)1259=== NAME TestNARDeduplicationMetadataUploadBug1260 metadata_upload_test.go:54: Retrieved narinfo from S3:1261 StorePath: /nix/var/nix/builds/nix-52094-4089225465/TestNARDeduplicationMetadataUploadBug3543097603/001/store/550ih97mdzffp9fpkw0w4h35i9q08cqn-file1.txt1262 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1263 Compression: zstd1264 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1265 NarSize: 1601266 References: 1267 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1268 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1269 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1270 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}1271--- PASS: TestService_healthCheckHandler (1.81s)1272=== CONT TestParseSize1273--- PASS: TestParseSize (0.00s)1274=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle12752026-09-20 10:38:16.461 UTC [52328] ERROR: relation "goose_db_version" does not exist at character 3612762026-09-20 10:38:16.461 UTC [52328] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1277=== NAME TestNARDeduplicationMetadataUploadBug1278 metadata_upload_test.go:64: Second store path (same content): /nix/var/nix/builds/nix-52094-4089225465/TestNARDeduplicationMetadataUploadBug3543097603/001/store/jyrgnsgd4jw056gj5d2l88w5v82pvz64-file2.txt12792026/09/20 10:38:16 OK 20241026095416_initial_model.sql (114.8ms)12802026/09/20 10:38:16 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"12812026/09/20 10:38:16 OK 20251210153512_drop_unused_gin_index.sql (7.84ms)12822026/09/20 10:38:16 OK 20251218171726_add_pins.sql (30.2ms)12832026/09/20 10:38:16 INFO Received uploads request method=POST path=/api/pending_closures12842026/09/20 10:38:16 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)12852026/09/20 10:38:16 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign12862026/09/20 10:38:16 INFO Signed narinfos id=2 count=112872026/09/20 10:38:16 INFO Uploading 1 narinfos12882026/09/20 10:38:16 WARN Failed to register uploaded object key=jyrgnsgd4jw056gj5d2l88w5v82pvz64.ls error="server returned 404: 404 page not found\n"12892026/09/20 10:38:16 OK 20260628120000_add_object_size_and_stats.sql (32.18ms)12902026/09/20 10:38:16 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete12912026/09/20 10:38:16 WARN Failed to register uploaded object key=jyrgnsgd4jw056gj5d2l88w5v82pvz64.narinfo error="server returned 404: 404 page not found\n"12922026/09/20 10:38:16 INFO Completed upload id=212932026/09/20 10:38:16 INFO Upload complete. (126ms)1294 metadata_upload_test.go:76: Retrieved narinfo from S3:1295 StorePath: /nix/var/nix/builds/nix-52094-4089225465/TestNARDeduplicationMetadataUploadBug3543097603/001/store/jyrgnsgd4jw056gj5d2l88w5v82pvz64-file2.txt1296 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1297 Compression: zstd1298 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1299 NarSize: 1601300 References: 1301 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1302 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1303 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1304 {"version":1,"root":{"type":"regular","size":44}}13052026/09/20 10:38:16 OK 20260905000000_add_claims.sql (33.15ms)13062026-09-20 10:38:16.726 UTC [52337] ERROR: relation "goose_db_version" does not exist at character 3613072026-09-20 10:38:16.726 UTC [52337] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13082026/09/20 10:38:16 INFO Aborted multipart uploads count=013092026/09/20 10:38:16 OK 20260920000000_drop_claims.sql (23.32ms)13102026/09/20 10:38:16 goose: successfully migrated database to version: 2026092000000013112026/09/20 10:38:16 OK 1_commit_pending_closure.sql (1.27ms)13122026/09/20 10:38:16 OK 2_object_stats_trigger.sql (254.5µs)13132026/09/20 10:38:16 goose: up to current file version: 213142026/09/20 10:38:16 WARN Force mode enabled - objects will be deleted immediately without grace period13152026/09/20 10:38:16 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=013162026/09/20 10:38:16 INFO Vacuumed table table=pending_closures13172026/09/20 10:38:16 INFO Vacuumed table table=pending_objects13182026/09/20 10:38:16 INFO Vacuumed table table=multipart_uploads13192026/09/20 10:38:16 INFO Vacuumed table table=closures13202026/09/20 10:38:16 INFO Vacuumed table table=objects1321--- PASS: TestGCMetrics (1.61s)1322=== CONT TestSkippedUploadsHandler13232026/09/20 10:38:16 INFO Client skipped oversized paths paths=3 nar_bytes=50000000001324--- PASS: TestSkippedUploadsHandler (0.00s)1325=== CONT TestReadProxyRangeRequest1326--- PASS: TestNARDeduplicationMetadataUploadBug (2.33s)1327=== CONT TestService_RequireScope_OIDC13282026/09/20 10:38:16 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:54613/oidc13292026/09/20 10:38:16 OK 20241026095416_initial_model.sql (178.4ms)13302026/09/20 10:38:16 OK 20251210153512_drop_unused_gin_index.sql (9.04ms)13312026-09-20 10:38:16.971 UTC [52343] ERROR: relation "goose_db_version" does not exist at character 3613322026-09-20 10:38:16.971 UTC [52343] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13332026/09/20 10:38:17 OK 20251218171726_add_pins.sql (33.32ms)13342026/09/20 10:38:17 OK 20260628120000_add_object_size_and_stats.sql (15.77ms)13352026/09/20 10:38:17 OK 20260905000000_add_claims.sql (17.48ms)13362026/09/20 10:38:17 OK 20260920000000_drop_claims.sql (10.32ms)13372026/09/20 10:38:17 goose: successfully migrated database to version: 2026092000000013382026/09/20 10:38:17 OK 1_commit_pending_closure.sql (2.46ms)13392026/09/20 10:38:17 OK 2_object_stats_trigger.sql (565.21µs)13402026/09/20 10:38:17 goose: up to current file version: 213412026-09-20 10:38:17.064 UTC [52344] ERROR: relation "goose_db_version" does not exist at character 3613422026-09-20 10:38:17.064 UTC [52344] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13432026/09/20 10:38:17 OK 20241026095416_initial_model.sql (53.19ms)13442026/09/20 10:38:17 OK 20251210153512_drop_unused_gin_index.sql (8.21ms)13452026/09/20 10:38:17 OK 20251218171726_add_pins.sql (24ms)13462026/09/20 10:38:17 OK 20260628120000_add_object_size_and_stats.sql (19.1ms)13472026/09/20 10:38:17 OK 20260905000000_add_claims.sql (27.23ms)13482026/09/20 10:38:17 OK 20260920000000_drop_claims.sql (27.54ms)13492026/09/20 10:38:17 goose: successfully migrated database to version: 2026092000000013502026/09/20 10:38:17 OK 1_commit_pending_closure.sql (3.9ms)13512026/09/20 10:38:17 OK 2_object_stats_trigger.sql (735.21µs)13522026/09/20 10:38:17 goose: up to current file version: 213532026/09/20 10:38:17 OK 20241026095416_initial_model.sql (109.32ms)13542026/09/20 10:38:17 OK 20251210153512_drop_unused_gin_index.sql (2.08ms)13552026/09/20 10:38:17 OK 20251218171726_add_pins.sql (4.64ms)13562026/09/20 10:38:17 OK 20260628120000_add_object_size_and_stats.sql (31.93ms)1357--- PASS: TestGCBugBareHashReferences (2.05s)1358=== CONT TestClientCADerivations13592026/09/20 10:38:17 OK 20260905000000_add_claims.sql (16.56ms)13602026/09/20 10:38:17 OK 20260920000000_drop_claims.sql (8.99ms)13612026/09/20 10:38:17 goose: successfully migrated database to version: 2026092000000013622026/09/20 10:38:17 OK 1_commit_pending_closure.sql (1.74ms)13632026/09/20 10:38:17 OK 2_object_stats_trigger.sql (349.33µs)13642026/09/20 10:38:17 goose: up to current file version: 213652026-09-20 10:38:17.311 UTC [52351] ERROR: relation "goose_db_version" does not exist at character 3613662026-09-20 10:38:17.311 UTC [52351] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1367=== NAME TestPinProtectsFromGC1368 client_integration_test.go:731: Pinned store path: /nix/var/nix/builds/nix-52094-4089225465/TestPinProtectsFromGC2071605232/001/store/cr7hzgrdv1sirmqnkv2s5bw4h8qdhav3-pinned-file.txt1369 client_integration_test.go:732: Unpinned store path: /nix/var/nix/builds/nix-52094-4089225465/TestPinProtectsFromGC2071605232/001/store/zcljw5z4swispvdnvcx4npn0g2zg2av7-unpinned-file.txt13702026-09-20 10:38:17.429 UTC [52357] ERROR: relation "goose_db_version" does not exist at character 3613712026-09-20 10:38:17.429 UTC [52357] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13722026/09/20 10:38:17 OK 20241026095416_initial_model.sql (85.05ms)13732026/09/20 10:38:17 OK 20251210153512_drop_unused_gin_index.sql (8.83ms)13742026/09/20 10:38:17 OK 20251218171726_add_pins.sql (2.64ms)13752026/09/20 10:38:17 OK 20260628120000_add_object_size_and_stats.sql (17.96ms)13762026/09/20 10:38:17 OK 20260905000000_add_claims.sql (27.73ms)13772026/09/20 10:38:17 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"13782026/09/20 10:38:17 OK 20260920000000_drop_claims.sql (17.42ms)13792026/09/20 10:38:17 goose: successfully migrated database to version: 2026092000000013802026/09/20 10:38:17 OK 1_commit_pending_closure.sql (23.66ms)13812026/09/20 10:38:17 OK 20241026095416_initial_model.sql (85.89ms)13822026/09/20 10:38:17 OK 2_object_stats_trigger.sql (528.21µs)13832026/09/20 10:38:17 goose: up to current file version: 213842026/09/20 10:38:17 OK 20251210153512_drop_unused_gin_index.sql (10.56ms)13852026/09/20 10:38:17 INFO Received uploads request method=POST path=/api/pending_closures13862026/09/20 10:38:17 OK 20251218171726_add_pins.sql (20.5ms)13872026/09/20 10:38:17 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)13882026/09/20 10:38:17 INFO Uploading cr7hzgrdv1sirmqnkv2s5bw4h8qdhav3-pinned-file.txt (128B)13892026/09/20 10:38:17 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"13902026/09/20 10:38:17 OK 20260628120000_add_object_size_and_stats.sql (15.77ms)13912026/09/20 10:38:17 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign13922026/09/20 10:38:17 WARN Failed to register uploaded object key=cr7hzgrdv1sirmqnkv2s5bw4h8qdhav3.ls error="server returned 404: 404 page not found\n"13932026/09/20 10:38:17 INFO Signed narinfos id=1 count=113942026/09/20 10:38:17 INFO Uploading 1 narinfos13952026/09/20 10:38:17 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete13962026/09/20 10:38:17 WARN Failed to register uploaded object key=cr7hzgrdv1sirmqnkv2s5bw4h8qdhav3.narinfo error="server returned 404: 404 page not found\n"13972026/09/20 10:38:17 OK 20260905000000_add_claims.sql (32.96ms)13982026/09/20 10:38:17 INFO Completed upload id=113992026/09/20 10:38:17 INFO Upload complete. (163ms)14002026/09/20 10:38:17 OK 20260920000000_drop_claims.sql (3.43ms)14012026/09/20 10:38:17 goose: successfully migrated database to version: 2026092000000014022026/09/20 10:38:17 OK 1_commit_pending_closure.sql (6.09ms)14032026/09/20 10:38:17 OK 2_object_stats_trigger.sql (633.67µs)14042026/09/20 10:38:17 goose: up to current file version: 214052026-09-20 10:38:17.637 UTC [52371] ERROR: relation "goose_db_version" does not exist at character 3614062026-09-20 10:38:17.637 UTC [52371] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14072026-09-20 10:38:17.637 UTC [52372] ERROR: relation "goose_db_version" does not exist at character 3614082026-09-20 10:38:17.637 UTC [52372] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14092026/09/20 10:38:17 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"14102026/09/20 10:38:17 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"14112026/09/20 10:38:17 OK 20241026095416_initial_model.sql (45.27ms)14122026/09/20 10:38:17 INFO Received uploads request method=POST path=/api/pending_closures14132026/09/20 10:38:17 OK 20251210153512_drop_unused_gin_index.sql (7.52ms)14142026/09/20 10:38:17 OK 20241026095416_initial_model.sql (53.58ms)14152026/09/20 10:38:17 OK 20251210153512_drop_unused_gin_index.sql (807.46µs)14162026/09/20 10:38:17 OK 20251218171726_add_pins.sql (9.05ms)14172026/09/20 10:38:17 OK 20251218171726_add_pins.sql (9.17ms)14182026/09/20 10:38:17 INFO Received uploads request method=POST path=/api/pending_closures14192026/09/20 10:38:17 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)14202026/09/20 10:38:17 INFO Uploading zcljw5z4swispvdnvcx4npn0g2zg2av7-unpinned-file.txt (128B)14212026/09/20 10:38:17 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"14222026/09/20 10:38:17 OK 20260628120000_add_object_size_and_stats.sql (15.97ms)14232026/09/20 10:38:17 OK 20260628120000_add_object_size_and_stats.sql (15.25ms)14242026/09/20 10:38:17 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign14252026/09/20 10:38:17 INFO Signed narinfos id=2 count=114262026/09/20 10:38:17 INFO Uploading 1 narinfos14272026/09/20 10:38:17 WARN Failed to register uploaded object key=zcljw5z4swispvdnvcx4npn0g2zg2av7.ls error="server returned 404: 404 page not found\n"14282026/09/20 10:38:17 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete14292026/09/20 10:38:17 WARN Failed to register uploaded object key=zcljw5z4swispvdnvcx4npn0g2zg2av7.narinfo error="server returned 404: 404 page not found\n"14302026/09/20 10:38:17 INFO Completed upload id=214312026/09/20 10:38:17 INFO Upload complete. (106ms)14322026/09/20 10:38:17 OK 20260905000000_add_claims.sql (20.59ms)14332026/09/20 10:38:17 OK 20260905000000_add_claims.sql (20.45ms)14342026/09/20 10:38:17 OK 20260920000000_drop_claims.sql (12.5ms)14352026/09/20 10:38:17 goose: successfully migrated database to version: 2026092000000014362026/09/20 10:38:17 OK 20260920000000_drop_claims.sql (12.77ms)14372026/09/20 10:38:17 goose: successfully migrated database to version: 2026092000000014382026/09/20 10:38:17 OK 1_commit_pending_closure.sql (1.56ms)14392026/09/20 10:38:17 OK 1_commit_pending_closure.sql (2.05ms)14402026/09/20 10:38:17 OK 2_object_stats_trigger.sql (465.21µs)14412026/09/20 10:38:17 goose: up to current file version: 214422026/09/20 10:38:17 OK 2_object_stats_trigger.sql (430.96µs)14432026/09/20 10:38:17 goose: up to current file version: 214442026/09/20 10:38:17 INFO Received create pin request method=POST path=/api/pins/myapp1445=== NAME TestOrphanedObjectsGCStressTest1446 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains14472026/09/20 10:38:17 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"14482026/09/20 10:38:17 INFO Created/updated pin name=myapp store_path=/nix/var/nix/builds/nix-52094-4089225465/TestPinProtectsFromGC2071605232/001/store/cr7hzgrdv1sirmqnkv2s5bw4h8qdhav3-pinned-file.txt narinfo_key=cr7hzgrdv1sirmqnkv2s5bw4h8qdhav3.narinfo14492026/09/20 10:38:17 INFO Starting cleanup of old closures method=DELETE path=/api/closures14502026/09/20 10:38:17 INFO Garbage collection started14512026/09/20 10:38:17 INFO Aborted multipart uploads count=014522026/09/20 10:38:17 WARN Force mode enabled - objects will be deleted immediately without grace period1453 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion14542026/09/20 10:38:17 INFO Received uploads request method=POST path=/api/pending_closures14552026/09/20 10:38:17 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)14562026/09/20 10:38:17 INFO Uploading 2nfvg3ms28wnazmf9p6p3rdwrfrf8vgc-shared-dep (136B)14572026/09/20 10:38:17 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"14582026/09/20 10:38:17 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign14592026-09-20 10:38:17.866 UTC [52399] ERROR: relation "goose_db_version" does not exist at character 3614602026-09-20 10:38:17.866 UTC [52399] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14612026/09/20 10:38:17 WARN Failed to register uploaded object key=2nfvg3ms28wnazmf9p6p3rdwrfrf8vgc.ls error="server returned 404: 404 page not found\n"14622026/09/20 10:38:17 INFO Signed narinfos id=2 count=114632026/09/20 10:38:17 INFO Uploading 1 narinfos14642026/09/20 10:38:17 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete14652026/09/20 10:38:17 WARN Failed to register uploaded object key=2nfvg3ms28wnazmf9p6p3rdwrfrf8vgc.narinfo error="server returned 404: 404 page not found\n"1466=== NAME TestClientWithDependencies1467 client_integration_test.go:613: Built derivation: /nix/var/nix/builds/nix-52094-4089225465/TestClientWithDependencies4176036920/001/store/srjz3nflq2r163snz8fa6l4n0n0vg6d6-test-script14682026/09/20 10:38:17 INFO Completed upload id=214692026/09/20 10:38:17 INFO Upload complete. (144ms)14702026/09/20 10:38:17 INFO Received uploads request method=POST path=/api/pending_closures14712026/09/20 10:38:17 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)14722026/09/20 10:38:17 INFO Uploading cfx96j7qkf3546vh9v0prpmgcpm54hzz-top (256B)14732026/09/20 10:38:17 INFO Uploading 2nfvg3ms28wnazmf9p6p3rdwrfrf8vgc-shared-dep (136B)14742026/09/20 10:38:17 WARN Failed to register uploaded object key=nar/17ka9kyac5simk2cdbl7fpq68jvm93qsij52nh68aimx7mggi4c0.nar.zst error="server returned 404: 404 page not found\n"14752026/09/20 10:38:17 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"1476=== NAME TestClientMultipleUploads1477 client_integration_test.go:358: Created store path 0: /nix/var/nix/builds/nix-52094-4089225465/TestClientMultipleUploads1257008241/001/store/hgqp1d4y41hwzcxnz9hmcwd9pfadm7yy-test-file-0.txt14782026/09/20 10:38:17 WARN Failed to register uploaded object key=cfx96j7qkf3546vh9v0prpmgcpm54hzz.ls error="server returned 404: 404 page not found\n"14792026/09/20 10:38:17 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign14802026/09/20 10:38:17 INFO Signed narinfos id=1 count=114812026/09/20 10:38:17 WARN Failed to register uploaded object key=2nfvg3ms28wnazmf9p6p3rdwrfrf8vgc.ls error="server returned 404: 404 page not found\n"14822026/09/20 10:38:17 INFO Received sign narinfos request method=POST path=/api/pending_closures/3/sign14832026/09/20 10:38:17 INFO Signed narinfos id=3 count=114842026/09/20 10:38:17 INFO Uploading 2 narinfos1485=== NAME TestClientWithDependencies1486 client_integration_test.go:615: Found 1 dependencies (including self)14872026/09/20 10:38:17 WARN Failed to register uploaded object key=cfx96j7qkf3546vh9v0prpmgcpm54hzz.narinfo error="server returned 404: 404 page not found\n"14882026/09/20 10:38:17 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete14892026/09/20 10:38:17 WARN Failed to register uploaded object key=2nfvg3ms28wnazmf9p6p3rdwrfrf8vgc.narinfo error="server returned 404: 404 page not found\n"14902026/09/20 10:38:17 INFO Completed upload id=114912026/09/20 10:38:17 INFO Received complete upload request method=POST path=/api/pending_closures/3/complete14922026/09/20 10:38:17 INFO Completed upload id=314932026/09/20 10:38:17 INFO Upload complete. (330ms)1494=== NAME TestClientSharedPathCommittedMidPush1495 client_integration_test.go:680: Retrieved narinfo from S3:1496 StorePath: /nix/var/nix/builds/nix-52094-4089225465/TestClientSharedPathCommittedMidPush4062231584/001/store/2nfvg3ms28wnazmf9p6p3rdwrfrf8vgc-shared-dep1497 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1498 Compression: zstd1499 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821500 NarSize: 1361501 References: 1502 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1503 client_integration_test.go:680: Retrieved narinfo from S3:1504 StorePath: /nix/var/nix/builds/nix-52094-4089225465/TestClientSharedPathCommittedMidPush4062231584/001/store/cfx96j7qkf3546vh9v0prpmgcpm54hzz-top1505 URL: nar/17ka9kyac5simk2cdbl7fpq68jvm93qsij52nh68aimx7mggi4c0.nar.zst1506 Compression: zstd1507 NarHash: sha256:17ka9kyac5simk2cdbl7fpq68jvm93qsij52nh68aimx7mggi4c01508 NarSize: 2561509 References: /nix/var/nix/builds/nix-52094-4089225465/TestClientSharedPathCommittedMidPush4062231584/001/store/2nfvg3ms28wnazmf9p6p3rdwrfrf8vgc-shared-dep1510 CA: text:sha256:0lchj1bbrlcx4wv60qbbcfb81vszm2pvr8y3fmg96h819fp511my15112026/09/20 10:38:17 OK 20241026095416_initial_model.sql (59.54ms)15122026/09/20 10:38:17 OK 20251210153512_drop_unused_gin_index.sql (13.37ms)1513=== NAME TestClientMultipleUploads1514 client_integration_test.go:358: Created store path 1: /nix/var/nix/builds/nix-52094-4089225465/TestClientMultipleUploads1257008241/001/store/ny1mi4lhdxb6ckphw0c10qd6ypmbh59w-test-file-1.txt1515--- PASS: TestClientSharedPathCommittedMidPush (2.30s)1516=== CONT TestCacheStatsHandler15172026/09/20 10:38:17 OK 20251218171726_add_pins.sql (9.99ms)15182026/09/20 10:38:18 OK 20260628120000_add_object_size_and_stats.sql (15.35ms)15192026/09/20 10:38:18 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"15202026/09/20 10:38:18 INFO Received uploads request method=POST path=/api/pending_closures15212026/09/20 10:38:18 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15222026/09/20 10:38:18 INFO Uploading srjz3nflq2r163snz8fa6l4n0n0vg6d6-test-script (136B)15232026/09/20 10:38:18 OK 20260905000000_add_claims.sql (33.11ms)15242026/09/20 10:38:18 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"15252026/09/20 10:38:18 WARN Failed to register uploaded object key=srjz3nflq2r163snz8fa6l4n0n0vg6d6.ls error="server returned 404: 404 page not found\n"15262026/09/20 10:38:18 WARN Failed to register uploaded object key=log/vf3kc9b7zdskmvs0rg2fax484nx9r05z-test-script.drv error="server returned 404: 404 page not found\n"1527=== NAME TestClientMultipleUploads1528 client_integration_test.go:358: Created store path 2: /nix/var/nix/builds/nix-52094-4089225465/TestClientMultipleUploads1257008241/001/store/g1blqy2pp96ajd7jp2mwa0r7s4d859l4-test-file-2.txt15292026/09/20 10:38:18 OK 20260920000000_drop_claims.sql (13.74ms)15302026/09/20 10:38:18 goose: successfully migrated database to version: 2026092000000015312026/09/20 10:38:18 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign15322026/09/20 10:38:18 INFO Signed narinfos id=1 count=115332026/09/20 10:38:18 INFO Uploading 1 narinfos15342026/09/20 10:38:18 OK 1_commit_pending_closure.sql (1.41ms)15352026/09/20 10:38:18 OK 2_object_stats_trigger.sql (310.46µs)15362026/09/20 10:38:18 goose: up to current file version: 215372026/09/20 10:38:18 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=015382026/09/20 10:38:18 INFO Vacuumed table table=pending_closures15392026/09/20 10:38:18 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete15402026/09/20 10:38:18 WARN Failed to register uploaded object key=srjz3nflq2r163snz8fa6l4n0n0vg6d6.narinfo error="server returned 404: 404 page not found\n"15412026/09/20 10:38:18 INFO Completed upload id=115422026/09/20 10:38:18 INFO Vacuumed table table=pending_objects15432026/09/20 10:38:18 INFO Upload complete. (112ms)1544=== NAME TestClientWithDependencies1545 client_integration_test.go:617: Skipping nix copy test - isolated store (/nix/var/nix/builds/nix-52094-4089225465/TestClientWithDependencies4176036920/001/store) requires matching store prefix15462026/09/20 10:38:18 INFO Vacuumed table table=multipart_uploads15472026/09/20 10:38:18 INFO Vacuumed table table=closures15482026/09/20 10:38:18 INFO Vacuumed table table=objects15492026/09/20 10:38:18 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"1550--- PASS: TestClientWithDependencies (2.36s)1551=== CONT TestCacheConfigHandler1552=== RUN TestCacheConfigHandler/full_config,_no_issuer1553=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1554=== RUN TestCacheConfigHandler/no_cache_url_configured1555=== PAUSE TestCacheConfigHandler/no_cache_url_configured1556=== RUN TestCacheConfigHandler/no_signing_keys1557=== PAUSE TestCacheConfigHandler/no_signing_keys1558=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1559=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1560=== CONT TestService_ReadScope_PublicByDefault1561=== NAME TestClientIntegration1562 client_integration_test.go:286: Created store path: /nix/var/nix/builds/nix-52094-4089225465/TestClientIntegration1365968653/002/store/7rhpk5424n53kmmdnsywdwlw46ym96a2-test-file.txt15632026/09/20 10:38:18 INFO Received uploads request method=POST path=/api/pending_closures15642026/09/20 10:38:18 INFO Received uploads request method=POST path=/api/pending_closures15652026/09/20 10:38:18 INFO Received uploads request method=POST path=/api/pending_closures15662026/09/20 10:38:18 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)15672026/09/20 10:38:18 INFO Uploading g1blqy2pp96ajd7jp2mwa0r7s4d859l4-test-file-2.txt (160B)15682026/09/20 10:38:18 INFO Uploading hgqp1d4y41hwzcxnz9hmcwd9pfadm7yy-test-file-0.txt (160B)15692026/09/20 10:38:18 INFO Uploading ny1mi4lhdxb6ckphw0c10qd6ypmbh59w-test-file-1.txt (160B)15702026/09/20 10:38:18 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"15712026/09/20 10:38:18 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"15722026/09/20 10:38:18 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"15732026/09/20 10:38:18 INFO Received uploads request method=POST path=/api/pending_closures15742026/09/20 10:38:18 WARN Failed to register uploaded object key=hgqp1d4y41hwzcxnz9hmcwd9pfadm7yy.ls error="server returned 404: 404 page not found\n"15752026/09/20 10:38:18 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"15762026/09/20 10:38:18 WARN Failed to register uploaded object key=ny1mi4lhdxb6ckphw0c10qd6ypmbh59w.ls error="server returned 404: 404 page not found\n"15772026/09/20 10:38:18 WARN Failed to register uploaded object key=g1blqy2pp96ajd7jp2mwa0r7s4d859l4.ls error="server returned 404: 404 page not found\n"15782026/09/20 10:38:18 INFO Received sign narinfos request method=POST path=/api/pending_closures/3/sign15792026/09/20 10:38:18 INFO Signed narinfos id=3 count=115802026/09/20 10:38:18 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign15812026/09/20 10:38:18 INFO Signed narinfos id=1 count=115822026/09/20 10:38:18 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign15832026/09/20 10:38:18 INFO Signed narinfos id=2 count=115842026/09/20 10:38:18 INFO Uploading 3 narinfos15852026/09/20 10:38:18 WARN Failed to register uploaded object key=g1blqy2pp96ajd7jp2mwa0r7s4d859l4.narinfo error="server returned 404: 404 page not found\n"15862026/09/20 10:38:18 WARN Failed to register uploaded object key=ny1mi4lhdxb6ckphw0c10qd6ypmbh59w.narinfo error="server returned 404: 404 page not found\n"15872026/09/20 10:38:18 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete15882026/09/20 10:38:18 WARN Failed to register uploaded object key=hgqp1d4y41hwzcxnz9hmcwd9pfadm7yy.narinfo error="server returned 404: 404 page not found\n"15892026/09/20 10:38:18 INFO Completed upload id=115902026/09/20 10:38:18 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete15912026/09/20 10:38:18 INFO Completed upload id=215922026/09/20 10:38:18 INFO Received complete upload request method=POST path=/api/pending_closures/3/complete15932026/09/20 10:38:18 INFO Completed upload id=315942026/09/20 10:38:18 INFO Upload complete. (176ms)1595=== NAME TestClientMultipleUploads1596 client_integration_test.go:369: Uploaded 3 paths in 208.912167ms15972026/09/20 10:38:18 INFO Received uploads request method=POST path=/api/pending_closures15982026/09/20 10:38:18 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15992026/09/20 10:38:18 INFO Uploading 7rhpk5424n53kmmdnsywdwlw46ym96a2-test-file.txt (152B)1600--- PASS: TestClientMultipleUploads (2.43s)1601=== CONT TestReadRedirectNar16022026/09/20 10:38:18 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"16032026/09/20 10:38:18 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign16042026/09/20 10:38:18 INFO Signed narinfos id=1 count=116052026/09/20 10:38:18 WARN Failed to register uploaded object key=7rhpk5424n53kmmdnsywdwlw46ym96a2.ls error="server returned 404: 404 page not found\n"16062026/09/20 10:38:18 INFO Uploading 1 narinfos16072026/09/20 10:38:18 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete16082026/09/20 10:38:18 WARN Failed to register uploaded object key=7rhpk5424n53kmmdnsywdwlw46ym96a2.narinfo error="server returned 404: 404 page not found\n"16092026/09/20 10:38:18 INFO Completed upload id=116102026/09/20 10:38:18 INFO Upload complete. (209ms)16112026/09/20 10:38:18 INFO All 1 paths already cached1612=== NAME TestClientIntegration1613 client_integration_test.go:312: Retrieved narinfo from S3:1614 StorePath: /nix/var/nix/builds/nix-52094-4089225465/TestClientIntegration1365968653/002/store/7rhpk5424n53kmmdnsywdwlw46ym96a2-test-file.txt1615 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1616 Compression: zstd1617 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11618 NarSize: 1521619 References: 1620 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11621 client_integration_test.go:313: Retrieved .ls file from S3 (compressed size: 77 bytes)1622 client_integration_test.go:313: Decompressed .ls content (64 bytes):1623 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1624 client_integration_test.go:316: Testing garbage collection...16252026/09/20 10:38:18 INFO Starting cleanup of old closures method=DELETE path=/api/closures16262026/09/20 10:38:18 INFO Garbage collection started16272026/09/20 10:38:18 INFO Aborted multipart uploads count=016282026/09/20 10:38:18 WARN Force mode enabled - objects will be deleted immediately without grace period16292026/09/20 10:38:18 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1630--- PASS: TestReadProxyRangeRequest (1.77s)1631=== CONT TestService_AuthMiddleware_MTLSBoundSubjects1632=== RUN TestService_RequireScope_OIDC/builder_may_write1633=== PAUSE TestService_RequireScope_OIDC/builder_may_write1634=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1635=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1636=== RUN TestService_RequireScope_OIDC/ops_may_admin1637=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1638=== RUN TestService_RequireScope_OIDC/ops_may_not_write1639=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1640=== RUN TestService_RequireScope_OIDC/reader_may_not_write1641=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1642=== RUN TestService_RequireScope_OIDC/static_token_may_admin1643=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1644=== RUN TestService_RequireScope_OIDC/static_token_may_write1645=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1646=== RUN TestService_RequireScope_OIDC/reader_may_read1647=== PAUSE TestService_RequireScope_OIDC/reader_may_read1648=== RUN TestService_RequireScope_OIDC/writer_implies_read1649=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1650=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1651=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1652=== CONT TestService_AuthMiddleware_OIDC16532026/09/20 10:38:18 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=016542026/09/20 10:38:18 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:54685/oidc16552026/09/20 10:38:18 INFO Vacuumed table table=pending_closures16562026/09/20 10:38:18 INFO Vacuumed table table=pending_objects16572026/09/20 10:38:18 INFO Vacuumed table table=multipart_uploads16582026/09/20 10:38:18 INFO Vacuumed table table=closures16592026/09/20 10:38:18 INFO Vacuumed table table=objects16602026-09-20 10:38:19.089 UTC [52444] ERROR: relation "goose_db_version" does not exist at character 3616612026-09-20 10:38:19.089 UTC [52444] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16622026-09-20 10:38:19.165 UTC [52447] ERROR: relation "goose_db_version" does not exist at character 3616632026-09-20 10:38:19.165 UTC [52447] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16642026/09/20 10:38:19 OK 20241026095416_initial_model.sql (89.32ms)16652026/09/20 10:38:19 OK 20251210153512_drop_unused_gin_index.sql (8.7ms)16662026/09/20 10:38:19 OK 20251218171726_add_pins.sql (10.12ms)16672026/09/20 10:38:19 OK 20260628120000_add_object_size_and_stats.sql (45.73ms)1668=== NAME TestClientCADerivations16692026/09/20 10:38:19 OK 20241026095416_initial_model.sql (71.4ms)1670 client_ca_test.go:136: Built CA derivation: /nix/var/nix/builds/nix-52094-4089225465/TestClientCADerivations2368758328/001/store/wfw6ly0w4nxnbzi0xmkwajzvk0vx97zc-ca-test16712026/09/20 10:38:19 OK 20260905000000_add_claims.sql (11.24ms)16722026/09/20 10:38:19 OK 20251210153512_drop_unused_gin_index.sql (15.72ms)16732026/09/20 10:38:19 OK 20260920000000_drop_claims.sql (24.96ms)16742026/09/20 10:38:19 goose: successfully migrated database to version: 2026092000000016752026/09/20 10:38:19 OK 1_commit_pending_closure.sql (974.42µs)16762026/09/20 10:38:19 OK 20251218171726_add_pins.sql (15.1ms)16772026/09/20 10:38:19 OK 2_object_stats_trigger.sql (859µs)16782026/09/20 10:38:19 goose: up to current file version: 21679 client_ca_test.go:139: Found 1 dependencies (including self)16802026/09/20 10:38:19 OK 20260628120000_add_object_size_and_stats.sql (34.93ms)16812026/09/20 10:38:19 OK 20260905000000_add_claims.sql (45.6ms)16822026/09/20 10:38:19 OK 20260920000000_drop_claims.sql (34.63ms)16832026/09/20 10:38:19 goose: successfully migrated database to version: 2026092000000016842026/09/20 10:38:19 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"16852026/09/20 10:38:19 OK 1_commit_pending_closure.sql (2.83ms)16862026/09/20 10:38:19 OK 2_object_stats_trigger.sql (276.17µs)16872026/09/20 10:38:19 goose: up to current file version: 216882026/09/20 10:38:19 INFO Received uploads request method=POST path=/api/pending_closures16892026/09/20 10:38:19 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)16902026/09/20 10:38:19 INFO Uploading wfw6ly0w4nxnbzi0xmkwajzvk0vx97zc-ca-test (144B)16912026-09-20 10:38:19.509 UTC [52456] ERROR: relation "goose_db_version" does not exist at character 3616922026-09-20 10:38:19.509 UTC [52456] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16932026/09/20 10:38:19 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"16942026/09/20 10:38:19 WARN Failed to register uploaded object key=log/9687q16bai7sidjdjc11a335s5qmv3nk-ca-test.drv error="server returned 404: 404 page not found\n"16952026/09/20 10:38:19 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign16962026/09/20 10:38:19 WARN Failed to register uploaded object key=wfw6ly0w4nxnbzi0xmkwajzvk0vx97zc.ls error="server returned 404: 404 page not found\n"16972026/09/20 10:38:19 INFO Signed narinfos id=1 count=116982026/09/20 10:38:19 INFO Uploading 1 narinfos1699=== NAME TestOrphanedObjectsGCStressTest1700 orphaned_objects_gc_test.go:509: Stress test completed successfully:1701 orphaned_objects_gc_test.go:510: - Active objects preserved: 201702 orphaned_objects_gc_test.go:511: - Objects deleted: 2101703 orphaned_objects_gc_test.go:512: - Total GC'd: 2101704--- PASS: TestOrphanedObjectsGCStressTest (6.62s)1705=== CONT TestService_ReadAuthMiddleware17062026/09/20 10:38:19 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete17072026/09/20 10:38:19 WARN Failed to register uploaded object key=wfw6ly0w4nxnbzi0xmkwajzvk0vx97zc.narinfo error="server returned 404: 404 page not found\n"17082026/09/20 10:38:19 INFO Completed upload id=117092026/09/20 10:38:19 INFO Upload complete. (167ms)1710=== NAME TestClientCADerivations1711 client_ca_test.go:180: Narinfo contains CA field: StorePath: /nix/var/nix/builds/nix-52094-4089225465/TestClientCADerivations2368758328/001/store/wfw6ly0w4nxnbzi0xmkwajzvk0vx97zc-ca-test1712 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1713 Compression: zstd1714 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1715 NarSize: 1441716 References: 1717 Deriver: /nix/var/nix/builds/nix-52094-4089225465/TestClientCADerivations2368758328/001/store/9687q16bai7sidjdjc11a335s5qmv3nk-ca-test.drv1718 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1719 client_ca_test.go:185: Checking for realisation files in S3...1720 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1721 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache17222026-09-20 10:38:19.561 UTC [52460] ERROR: relation "goose_db_version" does not exist at character 3617232026-09-20 10:38:19.561 UTC [52460] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1724 client_ca_test.go:258: nix copy output: error: binary cache 's3://bucket38?endpoint=http://localhost:54486®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/nix/var/nix/builds/nix-52094-4089225465/TestClientCADerivations2368758328/001/store'1725 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 117262026/09/20 10:38:19 OK 20241026095416_initial_model.sql (90.58ms)17272026/09/20 10:38:19 OK 20251210153512_drop_unused_gin_index.sql (11.42ms)1728--- PASS: TestCacheStatsHandler (1.66s)1729=== CONT TestService_AuthMiddleware_MTLSProxyHeader17302026/09/20 10:38:19 OK 20251218171726_add_pins.sql (30.15ms)1731--- PASS: TestClientCADerivations (2.43s)1732=== CONT TestReadProxy40417332026/09/20 10:38:19 OK 20260628120000_add_object_size_and_stats.sql (16.69ms)17342026/09/20 10:38:19 OK 20241026095416_initial_model.sql (101.96ms)17352026/09/20 10:38:19 OK 20251210153512_drop_unused_gin_index.sql (14.47ms)17362026/09/20 10:38:19 OK 20251218171726_add_pins.sql (19.03ms)17372026/09/20 10:38:19 OK 20260905000000_add_claims.sql (64.88ms)17382026/09/20 10:38:19 OK 20260628120000_add_object_size_and_stats.sql (30.91ms)17392026/09/20 10:38:19 OK 20260920000000_drop_claims.sql (22.94ms)17402026/09/20 10:38:19 goose: successfully migrated database to version: 2026092000000017412026/09/20 10:38:19 OK 1_commit_pending_closure.sql (1.05ms)17422026/09/20 10:38:19 OK 2_object_stats_trigger.sql (240.17µs)17432026/09/20 10:38:19 goose: up to current file version: 217442026/09/20 10:38:19 OK 20260905000000_add_claims.sql (43.43ms)17452026/09/20 10:38:19 OK 20260920000000_drop_claims.sql (9.46ms)17462026/09/20 10:38:19 goose: successfully migrated database to version: 2026092000000017472026/09/20 10:38:19 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=017482026/09/20 10:38:19 OK 1_commit_pending_closure.sql (1.14ms)17492026/09/20 10:38:19 OK 2_object_stats_trigger.sql (268.71µs)17502026/09/20 10:38:19 goose: up to current file version: 21751=== NAME TestPinProtectsFromGC1752 client_integration_test.go:794: Pin successfully protected closure from garbage collection1753--- PASS: TestService_ReadScope_PublicByDefault (1.72s)1754=== CONT TestReadProxyInvalidPath1755--- PASS: TestPinProtectsFromGC (4.20s)1756=== CONT TestParseSingleRange/none1757=== CONT TestService_Rustfstest17582026-09-20 10:38:19.953 UTC [52470] ERROR: relation "goose_db_version" does not exist at character 3617592026-09-20 10:38:19.953 UTC [52470] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1760--- PASS: TestReadRedirectNar (1.81s)1761=== CONT TestReadProxyNarStreaming17622026/09/20 10:38:20 OK 20241026095416_initial_model.sql (160.4ms)17632026/09/20 10:38:20 OK 20251210153512_drop_unused_gin_index.sql (16.38ms)17642026/09/20 10:38:20 OK 20251218171726_add_pins.sql (20.43ms)17652026/09/20 10:38:20 OK 20260628120000_add_object_size_and_stats.sql (24.06ms)17662026/09/20 10:38:20 OK 20260905000000_add_claims.sql (51.61ms)17672026/09/20 10:38:20 OK 20260920000000_drop_claims.sql (35.76ms)17682026/09/20 10:38:20 goose: successfully migrated database to version: 2026092000000017692026/09/20 10:38:20 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"17702026/09/20 10:38:20 WARN mTLS auth: bound subjects configured but subject DN unavailable17712026/09/20 10:38:20 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1772--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (1.87s)1773=== CONT TestPresignedUploadRegisteredBeforeCommit17742026/09/20 10:38:20 OK 1_commit_pending_closure.sql (4.86ms)17752026/09/20 10:38:20 OK 2_object_stats_trigger.sql (4.25ms)17762026/09/20 10:38:20 goose: up to current file version: 217772026/09/20 10:38:20 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=01778=== NAME TestClientIntegration1779 client_integration_test.go:323: Objects in database after GC:1780 client_integration_test.go:323: Successfully deleted all objects with GC --force1781=== CONT TestParseSingleRange/open-ended1782=== CONT TestParseSingleRange/start_far_past_EOF1783=== CONT TestParseSingleRange/start_past_EOF1784=== CONT TestParseSingleRange/single_byte1785=== CONT TestParseSingleRange/suffix_exceeds_size1786=== CONT TestParseSingleRange/suffix1787=== CONT TestParseSingleRange/end_clamped_to_size1788=== CONT TestParseSingleRange/malformed_both_empty1789=== CONT TestParseSingleRange/closed1790=== CONT TestParseSingleRange/malformed_end_before_start1791=== CONT TestParseSingleRange/multi-range_ignored1792=== CONT TestParseSingleRange/malformed_no_dash1793=== CONT TestParseSingleRange/unknown_unit1794--- PASS: TestParseSingleRange (0.00s)1795 --- PASS: TestParseSingleRange/none (0.00s)1796 --- PASS: TestParseSingleRange/open-ended (0.00s)1797 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1798 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1799 --- PASS: TestParseSingleRange/single_byte (0.00s)1800 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1801 --- PASS: TestParseSingleRange/suffix (0.00s)1802 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1803 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1804 --- PASS: TestParseSingleRange/closed (0.00s)1805 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1806 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1807 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1808 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1809--- PASS: TestClientIntegration (4.27s)1810=== CONT TestReadRedirectKeepsNarinfoProxied1811=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1812=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1813=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1814=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1815=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1816=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1817=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1818=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1819=== CONT TestIsValidCachePath/narinfo1820=== CONT TestIsValidCachePath/index.html1821=== CONT TestIsValidCachePath/short_hash1822=== CONT TestIsValidCachePath/wrong_extension1823=== CONT TestIsValidCachePath/leading_slash1824=== CONT TestIsValidCachePath/empty1825=== CONT TestIsValidCachePath/random_path1826=== CONT TestIsValidCachePath/invalid_char_u1827=== CONT TestIsValidCachePath/invalid_char_e1828=== CONT TestIsValidCachePath/traversal_in_middle1829=== CONT TestIsValidCachePath/traversal_parent1830=== CONT TestIsValidCachePath/nar_uncompressed1831=== CONT TestIsValidCachePath/nix-cache-info1832=== CONT TestIsValidCachePath/realisation1833=== CONT TestIsValidCachePath/log1834=== CONT TestIsValidCachePath/ls1835=== CONT TestIsValidCachePath/nar_xz1836=== CONT TestIsValidCachePath/nar_bz21837=== CONT TestIsValidCachePath/nar_zst1838=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1839--- PASS: TestIsValidCachePath (0.00s)1840 --- PASS: TestIsValidCachePath/narinfo (0.00s)1841 --- PASS: TestIsValidCachePath/index.html (0.00s)1842 --- PASS: TestIsValidCachePath/short_hash (0.00s)1843 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1844 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1845 --- PASS: TestIsValidCachePath/empty (0.00s)1846 --- PASS: TestIsValidCachePath/random_path (0.00s)1847 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1848 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1849 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1850 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1851 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1852 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1853 --- PASS: TestIsValidCachePath/realisation (0.00s)1854 --- PASS: TestIsValidCachePath/log (0.00s)1855 --- PASS: TestIsValidCachePath/ls (0.00s)1856 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1857 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1858 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1859 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1860=== CONT TestProxyWriteTimeout/narinfo1861=== CONT TestProxyWriteTimeout/10_GiB_nar1862=== CONT TestProxyWriteTimeout/unknown_size1863=== CONT TestProxyWriteTimeout/1_GiB_nar1864--- PASS: TestProxyWriteTimeout (0.00s)1865 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1866 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1867 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1868 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1869=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart18702026/09/20 10:38:20 INFO Received complete multipart upload request method=POST path=/18712026-09-20 10:38:20.659 UTC [52477] ERROR: relation "goose_db_version" does not exist at character 3618722026-09-20 10:38:20.659 UTC [52477] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1873=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure18742026/09/20 10:38:20 INFO Received uploads request method=POST path=/18752026/09/20 10:38:20 OK 20241026095416_initial_model.sql (18.15ms)18762026/09/20 10:38:20 OK 20251210153512_drop_unused_gin_index.sql (848.17µs)18772026/09/20 10:38:20 OK 20251218171726_add_pins.sql (1.04ms)18782026-09-20 10:38:20.692 UTC [52478] ERROR: relation "goose_db_version" does not exist at character 3618792026-09-20 10:38:20.692 UTC [52478] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18802026/09/20 10:38:20 OK 20260628120000_add_object_size_and_stats.sql (7.64ms)18812026/09/20 10:38:20 OK 20260905000000_add_claims.sql (2.89ms)18822026/09/20 10:38:20 OK 20260920000000_drop_claims.sql (664.29µs)18832026/09/20 10:38:20 goose: successfully migrated database to version: 2026092000000018842026/09/20 10:38:20 OK 1_commit_pending_closure.sql (1.3ms)18852026/09/20 10:38:20 OK 2_object_stats_trigger.sql (240.08µs)18862026/09/20 10:38:20 goose: up to current file version: 218872026/09/20 10:38:20 OK 20241026095416_initial_model.sql (53.24ms)18882026/09/20 10:38:20 OK 20251210153512_drop_unused_gin_index.sql (991.96µs)18892026/09/20 10:38:20 OK 20251218171726_add_pins.sql (21.26ms)18902026/09/20 10:38:20 OK 20260628120000_add_object_size_and_stats.sql (18.14ms)18912026/09/20 10:38:20 OK 20260905000000_add_claims.sql (22.67ms)18922026/09/20 10:38:20 OK 20260920000000_drop_claims.sql (6.19ms)18932026/09/20 10:38:20 goose: successfully migrated database to version: 2026092000000018942026/09/20 10:38:20 OK 1_commit_pending_closure.sql (1.06ms)18952026/09/20 10:38:20 OK 2_object_stats_trigger.sql (712.08µs)18962026/09/20 10:38:20 goose: up to current file version: 218972026-09-20 10:38:20.855 UTC [52479] ERROR: relation "goose_db_version" does not exist at character 3618982026-09-20 10:38:20.855 UTC [52479] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1899--- PASS: TestService_ReadAuthMiddleware (1.37s)1900=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts19012026/09/20 10:38:20 INFO Received request for more parts method=POST path=/1902=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info19032026/09/20 10:38:20 INFO Received uploads request method=POST path=/1904=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key19052026/09/20 10:38:20 INFO Received complete multipart upload request method=POST path=/1906=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key19072026/09/20 10:38:20 INFO Received request for more parts method=POST path=/1908=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal19092026/09/20 10:38:20 INFO Received uploads request method=POST path=/1910--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)1911 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1912 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1913 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1914 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1915=== CONT TestIsValidUploadKey/narinfo1916=== CONT TestIsValidUploadKey/realisation_plus_in_output1917=== CONT TestIsValidUploadKey/unknown_type1918=== CONT TestIsValidUploadKey/empty_key1919=== CONT TestIsValidUploadKey/absolute1920=== CONT TestIsValidUploadKey/traversal_nar1921=== CONT TestIsValidUploadKey/traversal1922=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1923=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1924=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1925=== CONT TestIsValidUploadKey/index.html1926=== CONT TestIsValidUploadKey/nix-cache-info1927=== CONT TestIsValidUploadKey/build_log_home-manager_file1928=== CONT TestIsValidUploadKey/realisation1929=== CONT TestIsValidUploadKey/build_log_equals1930=== CONT TestIsValidUploadKey/build_log_question_mark1931=== CONT TestIsValidUploadKey/build_log_plus_in_name1932=== CONT TestIsValidUploadKey/nar_plain1933=== CONT TestIsValidUploadKey/build_log1934=== CONT TestIsValidUploadKey/listing1935=== CONT TestIsValidUploadKey/nar_xz1936=== CONT TestIsValidUploadKey/nar_zst1937--- PASS: TestIsValidUploadKey (0.00s)1938 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1939 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1940 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1941 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1942 --- PASS: TestIsValidUploadKey/absolute (0.00s)1943 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1944 --- PASS: TestIsValidUploadKey/traversal (0.00s)1945 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1946 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1947 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1948 --- PASS: TestIsValidUploadKey/index.html (0.00s)1949 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1950 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1951 --- PASS: TestIsValidUploadKey/realisation (0.00s)1952 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1953 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1954 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1955 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1956 --- PASS: TestIsValidUploadKey/build_log (0.00s)1957 --- PASS: TestIsValidUploadKey/listing (0.00s)1958 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1959 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1960=== CONT TestServerTLSConfig/no_client_CA1961=== CONT TestServerTLSConfig/not_a_PEM_file1962=== CONT TestServerTLSConfig/missing_CA_file1963--- PASS: TestServerTLSConfig (0.00s)1964 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1965 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)1966 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1967=== CONT TestClientErrorHandling/InvalidStorePath19682026/09/20 10:38:20 OK 20241026095416_initial_model.sql (47.43ms)19692026/09/20 10:38:20 OK 20251210153512_drop_unused_gin_index.sql (1.18ms)19702026-09-20 10:38:20.945 UTC [52482] ERROR: relation "goose_db_version" does not exist at character 3619712026-09-20 10:38:20.945 UTC [52482] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC19722026/09/20 10:38:20 OK 20251218171726_add_pins.sql (3.55ms)19732026/09/20 10:38:20 OK 20260628120000_add_object_size_and_stats.sql (28.51ms)19742026/09/20 10:38:20 OK 20260905000000_add_claims.sql (10.78ms)19752026/09/20 10:38:20 OK 20260920000000_drop_claims.sql (8.57ms)19762026/09/20 10:38:20 goose: successfully migrated database to version: 2026092000000019772026/09/20 10:38:20 OK 1_commit_pending_closure.sql (884.29µs)19782026/09/20 10:38:20 OK 2_object_stats_trigger.sql (220.29µs)19792026/09/20 10:38:20 goose: up to current file version: 219802026-09-20 10:38:21.001 UTC [52483] ERROR: relation "goose_db_version" does not exist at character 3619812026-09-20 10:38:21.001 UTC [52483] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC19822026/09/20 10:38:21 OK 20241026095416_initial_model.sql (45.33ms)19832026/09/20 10:38:21 OK 20251210153512_drop_unused_gin_index.sql (5.82ms)19842026/09/20 10:38:21 OK 20251218171726_add_pins.sql (13.59ms)1985=== CONT TestClientErrorHandling/ServerNotAvailable1986--- PASS: TestUploadHandlersRejectOversizedBody (0.12s)1987 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.03s)1988 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.02s)1989 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.40s)19902026/09/20 10:38:21 OK 20260628120000_add_object_size_and_stats.sql (31.04ms)1991--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (1.45s)1992=== CONT TestClientErrorHandling/InvalidAuthToken19932026/09/20 10:38:21 OK 20260905000000_add_claims.sql (8.86ms)19942026/09/20 10:38:21 OK 20260920000000_drop_claims.sql (2.92ms)19952026/09/20 10:38:21 goose: successfully migrated database to version: 2026092000000019962026/09/20 10:38:21 OK 20241026095416_initial_model.sql (45.62ms)19972026/09/20 10:38:21 OK 1_commit_pending_closure.sql (1.52ms)19982026/09/20 10:38:21 OK 20251210153512_drop_unused_gin_index.sql (1.02ms)19992026/09/20 10:38:21 OK 2_object_stats_trigger.sql (707.92µs)20002026/09/20 10:38:21 goose: up to current file version: 220012026-09-20 10:38:21.096 UTC [52486] ERROR: relation "goose_db_version" does not exist at character 3620022026-09-20 10:38:21.096 UTC [52486] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC20032026/09/20 10:38:21 OK 20251218171726_add_pins.sql (4.73ms)20042026/09/20 10:38:21 OK 20260628120000_add_object_size_and_stats.sql (14.98ms)20052026/09/20 10:38:21 OK 20260905000000_add_claims.sql (15.66ms)20062026/09/20 10:38:21 OK 20260920000000_drop_claims.sql (1.64ms)20072026/09/20 10:38:21 goose: successfully migrated database to version: 2026092000000020082026/09/20 10:38:21 OK 1_commit_pending_closure.sql (1.36ms)20092026/09/20 10:38:21 OK 2_object_stats_trigger.sql (260.71µs)20102026/09/20 10:38:21 goose: up to current file version: 220112026/09/20 10:38:21 OK 20241026095416_initial_model.sql (43.55ms)20122026/09/20 10:38:21 OK 20251210153512_drop_unused_gin_index.sql (27.38ms)20132026/09/20 10:38:21 OK 20251218171726_add_pins.sql (9.99ms)20142026/09/20 10:38:21 OK 20260628120000_add_object_size_and_stats.sql (9.8ms)20152026/09/20 10:38:21 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/present20162026/09/20 10:38:21 OK 20260905000000_add_claims.sql (24.82ms)20172026/09/20 10:38:21 OK 20260920000000_drop_claims.sql (1.63ms)20182026/09/20 10:38:21 goose: successfully migrated database to version: 2026092000000020192026/09/20 10:38:21 OK 1_commit_pending_closure.sql (844.75µs)20202026/09/20 10:38:21 OK 2_object_stats_trigger.sql (213µs)20212026/09/20 10:38:21 goose: up to current file version: 22022--- PASS: TestReadProxy404 (1.59s)2023=== CONT TestResolveDBConnectionString/flag_wins2024=== CONT TestResolveDBConnectionString/PGHOST_allows_empty2025=== CONT TestResolveDBConnectionString/nothing_configured2026=== CONT TestResolveDBConnectionString/missing_file_is_an_error2027=== CONT TestResolveDBConnectionString/file_when_flag_empty2028=== CONT TestCacheConfigHandler/full_config,_no_issuer2029=== CONT TestCacheConfigHandler/no_signing_keys2030=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator2031=== CONT TestCacheConfigHandler/no_cache_url_configured2032--- PASS: TestCacheConfigHandler (0.00s)2033 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)2034 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)2035 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)2036 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)2037=== CONT TestService_RequireScope_OIDC/builder_may_write2038--- PASS: TestResolveDBConnectionString (0.01s)2039 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)2040 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)2041 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)2042 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)2043 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)20442026/09/20 10:38:21 INFO OIDC auth successful provider=test scopes=[write]2045=== CONT TestService_RequireScope_OIDC/static_token_may_admin2046=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read2047=== CONT TestService_RequireScope_OIDC/writer_implies_read20482026/09/20 10:38:21 INFO OIDC auth successful provider=test scopes=[write]2049=== CONT TestService_RequireScope_OIDC/reader_may_read20502026/09/20 10:38:21 INFO OIDC auth successful provider=test scopes=[read]2051=== CONT TestService_RequireScope_OIDC/static_token_may_write2052=== CONT TestService_RequireScope_OIDC/ops_may_not_write20532026/09/20 10:38:21 INFO OIDC auth successful provider=test scopes=[admin]2054=== CONT TestService_RequireScope_OIDC/reader_may_not_write20552026/09/20 10:38:21 INFO OIDC auth successful provider=test scopes=[read]2056=== CONT TestService_RequireScope_OIDC/ops_may_admin20572026/09/20 10:38:21 INFO OIDC auth successful provider=test scopes=[admin]2058=== CONT TestService_RequireScope_OIDC/builder_may_not_admin20592026/09/20 10:38:21 INFO OIDC auth successful provider=test scopes=[write]2060=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token2061--- PASS: TestService_RequireScope_OIDC (1.91s)2062 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)2063 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)2064 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)2065 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)2066 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)2067 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)2068 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)2069 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)2070 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)2071 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)20722026/09/20 10:38:21 INFO OIDC auth successful provider=test scopes=[write]2073=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2074=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected20752026/09/20 10:38:21 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]2076=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected20772026/09/20 10:38:21 WARN Authentication failed token_preview=eyJhbGciOi...s__TxFW3QQ token_length=702 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]2078--- PASS: TestService_AuthMiddleware_OIDC (1.97s)2079 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)2080 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)2081 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)2082 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)20832026-09-20 10:38:21.303 UTC [52491] ERROR: relation "goose_db_version" does not exist at character 3620842026-09-20 10:38:21.303 UTC [52491] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC20852026/09/20 10:38:21 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=206.326887ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present20862026/09/20 10:38:21 OK 20241026095416_initial_model.sql (30.69ms)20872026/09/20 10:38:21 OK 20251210153512_drop_unused_gin_index.sql (5.72ms)20882026-09-20 10:38:21.356 UTC [52492] ERROR: relation "goose_db_version" does not exist at character 3620892026-09-20 10:38:21.356 UTC [52492] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC20902026/09/20 10:38:21 OK 20251218171726_add_pins.sql (5.89ms)20912026/09/20 10:38:21 OK 20260628120000_add_object_size_and_stats.sql (13.49ms)20922026/09/20 10:38:21 OK 20260905000000_add_claims.sql (9.17ms)20932026/09/20 10:38:21 OK 20260920000000_drop_claims.sql (12.42ms)20942026/09/20 10:38:21 goose: successfully migrated database to version: 2026092000000020952026/09/20 10:38:21 OK 1_commit_pending_closure.sql (997.04µs)20962026/09/20 10:38:21 OK 2_object_stats_trigger.sql (210.5µs)20972026/09/20 10:38:21 goose: up to current file version: 220982026/09/20 10:38:21 OK 20241026095416_initial_model.sql (44.85ms)20992026/09/20 10:38:21 OK 20251210153512_drop_unused_gin_index.sql (6.52ms)21002026/09/20 10:38:21 OK 20251218171726_add_pins.sql (11.12ms)2101--- PASS: TestReadProxyInvalidPath (1.59s)21022026/09/20 10:38:21 OK 20260628120000_add_object_size_and_stats.sql (3.38ms)21032026/09/20 10:38:21 OK 20260905000000_add_claims.sql (10.01ms)21042026/09/20 10:38:21 OK 20260920000000_drop_claims.sql (11.09ms)21052026/09/20 10:38:21 goose: successfully migrated database to version: 2026092000000021062026/09/20 10:38:21 OK 1_commit_pending_closure.sql (1.41ms)21072026/09/20 10:38:21 OK 2_object_stats_trigger.sql (398.29µs)21082026/09/20 10:38:21 goose: up to current file version: 221092026/09/20 10:38:21 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=369.679827ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present21102026-09-20 10:38:21.563 UTC [52493] ERROR: relation "goose_db_version" does not exist at character 3621112026-09-20 10:38:21.563 UTC [52493] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC2112--- PASS: TestService_Rustfstest (1.70s)21132026/09/20 10:38:21 OK 20241026095416_initial_model.sql (44.13ms)21142026/09/20 10:38:21 OK 20251210153512_drop_unused_gin_index.sql (7.03ms)21152026/09/20 10:38:21 OK 20251218171726_add_pins.sql (9.46ms)21162026/09/20 10:38:21 OK 20260628120000_add_object_size_and_stats.sql (9.93ms)21172026/09/20 10:38:21 OK 20260905000000_add_claims.sql (20.73ms)21182026-09-20 10:38:21.668 UTC [52494] ERROR: relation "goose_db_version" does not exist at character 3621192026-09-20 10:38:21.668 UTC [52494] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC21202026/09/20 10:38:21 OK 20260920000000_drop_claims.sql (7.75ms)21212026/09/20 10:38:21 goose: successfully migrated database to version: 2026092000000021222026/09/20 10:38:21 OK 1_commit_pending_closure.sql (2.57ms)21232026/09/20 10:38:21 OK 2_object_stats_trigger.sql (567.83µs)21242026/09/20 10:38:21 goose: up to current file version: 22125--- PASS: TestReadProxyNarStreaming (1.59s)21262026/09/20 10:38:21 OK 20241026095416_initial_model.sql (39.06ms)21272026/09/20 10:38:21 OK 20251210153512_drop_unused_gin_index.sql (6.21ms)21282026/09/20 10:38:21 OK 20251218171726_add_pins.sql (11.75ms)21292026/09/20 10:38:21 OK 20260628120000_add_object_size_and_stats.sql (2.93ms)21302026/09/20 10:38:21 OK 20260905000000_add_claims.sql (17.14ms)21312026/09/20 10:38:21 OK 20260920000000_drop_claims.sql (7.48ms)21322026/09/20 10:38:21 goose: successfully migrated database to version: 2026092000000021332026/09/20 10:38:21 OK 1_commit_pending_closure.sql (2.74ms)21342026/09/20 10:38:21 OK 2_object_stats_trigger.sql (548.58µs)21352026/09/20 10:38:21 goose: up to current file version: 221362026/09/20 10:38:21 INFO Received uploads request method=POST path=/api/pending_closures21372026/09/20 10:38:21 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst21382026/09/20 10:38:21 INFO Received uploads request method=POST path=/api/pending_closures2139--- PASS: TestPresignedUploadRegisteredBeforeCommit (1.50s)21402026/09/20 10:38:21 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=839.640874ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present21412026/09/20 10:38:21 WARN Rate limiter enabled after throttle name=s3-test rate=521422026/09/20 10:38:21 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."2143=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle2144 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=102145 throttle_test.go:215: Rate limiter: enabled=true, rate=5.002146--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (5.53s)2147--- PASS: TestReadRedirectKeepsNarinfoProxied (1.48s)21482026/09/20 10:38:22 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"21492026/09/20 10:38:22 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"21502026/09/20 10:38:22 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"21512026/09/20 10:38:22 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.74944689s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present21522026/09/20 10:38:24 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-config21532026/09/20 10:38:24 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=213.8901ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21542026/09/20 10:38:24 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=430.279493ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21552026/09/20 10:38:25 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=848.082297ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21562026/09/20 10:38:26 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.591806706s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21572026/09/20 10:38:27 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"21582026/09/20 10:38:27 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_closures21592026/09/20 10:38:27 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=187.171281ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures21602026/09/20 10:38:28 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=417.084237ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures21612026/09/20 10:38:28 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=861.480426ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures21622026/09/20 10:38:29 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.721877893s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2163--- PASS: TestClientErrorHandling (0.00s)2164 --- PASS: TestClientErrorHandling/InvalidStorePath (1.25s)2165 --- PASS: TestClientErrorHandling/InvalidAuthToken (1.30s)2166 --- PASS: TestClientErrorHandling/ServerNotAvailable (10.10s)2167PASS2168{"timestamp":"2026-09-20T10:38:31.165616Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:54558","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(10)"}21692026-09-20 10:38:31.274 UTC [52136] LOG: received smart shutdown request21702026-09-20 10:38:31.275 UTC [52136] LOG: background worker "logical replication launcher" (PID 52146) exited with exit code 121712026-09-20 10:38:31.280 UTC [52141] LOG: shutting down21722026-09-20 10:38:31.281 UTC [52141] LOG: checkpoint starting: shutdown immediate21732026-09-20 10:38:32.485 UTC [52141] LOG: checkpoint complete: wrote 12786 buffers (78.0%), wrote 3 SLRU buffers; 0 WAL file(s) added, 0 removed, 15 recycled; write=0.904 s, sync=0.294 s, total=1.205 s; sync files=17735, longest=0.001 s, average=0.001 s; distance=246228 kB, estimate=246228 kB; lsn=0/10801FB0, redo lsn=0/10801FB021742026-09-20 10:38:32.490 UTC [52136] LOG: database system is shut down2175Running OIDC tests...2176=== RUN TestGlobMatch2177=== PAUSE TestGlobMatch2178=== RUN TestAudienceForIssuer2179=== PAUSE TestAudienceForIssuer2180=== RUN TestValidateToken_ValidToken2181=== PAUSE TestValidateToken_ValidToken2182=== RUN TestValidateToken_WrongAudience2183=== PAUSE TestValidateToken_WrongAudience2184=== RUN TestValidateToken_Expired2185=== PAUSE TestValidateToken_Expired2186=== RUN TestValidateToken_BoundClaimsMismatch2187=== PAUSE TestValidateToken_BoundClaimsMismatch2188=== RUN TestValidateToken_BoundSubjectMismatch2189=== PAUSE TestValidateToken_BoundSubjectMismatch2190=== RUN TestValidateToken_MultipleProviders2191=== PAUSE TestValidateToken_MultipleProviders2192=== RUN TestValidateToken_NoMatchingProvider2193=== PAUSE TestValidateToken_NoMatchingProvider2194=== RUN TestValidateToken_KubernetesServiceAccount2195=== PAUSE TestValidateToken_KubernetesServiceAccount2196=== RUN TestNewValidator_KubernetesRequiresCA2197=== PAUSE TestNewValidator_KubernetesRequiresCA2198=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2199=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2200=== RUN TestScopes_LegacyProviderDefaultsToWrite2201=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2202=== RUN TestScopes_Rules2203=== PAUSE TestScopes_Rules2204=== RUN TestScopes_ConfigValidation2205=== PAUSE TestScopes_ConfigValidation2206=== CONT TestGlobMatch2207=== RUN TestGlobMatch/foo_foo2208=== CONT TestScopes_LegacyProviderDefaultsToWrite2209=== PAUSE TestGlobMatch/foo_foo2210=== RUN TestGlobMatch/foo_bar2211=== PAUSE TestGlobMatch/foo_bar2212=== CONT TestValidateToken_NoMatchingProvider2213=== RUN TestGlobMatch/*_2214=== PAUSE TestGlobMatch/*_2215=== RUN TestGlobMatch/*_anything2216=== PAUSE TestGlobMatch/*_anything2217=== RUN TestGlobMatch/foo*_foo2218=== PAUSE TestGlobMatch/foo*_foo2219=== RUN TestGlobMatch/foo*_foobar2220=== PAUSE TestGlobMatch/foo*_foobar2221=== RUN TestGlobMatch/foo*_bar2222=== PAUSE TestGlobMatch/foo*_bar2223=== CONT TestValidateToken_MultipleProviders2224=== RUN TestGlobMatch/*bar_bar2225=== PAUSE TestGlobMatch/*bar_bar2226=== RUN TestGlobMatch/*bar_foobar2227=== PAUSE TestGlobMatch/*bar_foobar2228=== RUN TestGlobMatch/*bar_foo2229=== PAUSE TestGlobMatch/*bar_foo2230=== RUN TestGlobMatch/foo*bar_foobar2231=== PAUSE TestGlobMatch/foo*bar_foobar2232=== RUN TestGlobMatch/foo*bar_foo123bar2233=== PAUSE TestGlobMatch/foo*bar_foo123bar2234=== RUN TestGlobMatch/foo*bar_foobarbaz2235=== CONT TestValidateToken_BoundSubjectMismatch2236=== CONT TestValidateToken_BoundClaimsMismatch2237=== CONT TestValidateToken_Expired2238=== CONT TestValidateToken_WrongAudience2239=== CONT TestValidateToken_ValidToken2240=== CONT TestAudienceForIssuer2241--- PASS: TestAudienceForIssuer (0.00s)2242=== CONT TestNewValidator_KubernetesRequiresCA2243=== PAUSE TestGlobMatch/foo*bar_foobarbaz2244=== RUN TestGlobMatch/*/*_foo/bar2245=== PAUSE TestGlobMatch/*/*_foo/bar2246=== RUN TestGlobMatch/*/*_foo2247=== PAUSE TestGlobMatch/*/*_foo2248=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2249=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2250=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02251=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02252=== RUN TestGlobMatch/refs/*/main_refs/heads/main2253=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2254=== RUN TestGlobMatch/fo?_foo2255=== PAUSE TestGlobMatch/fo?_foo2256=== RUN TestGlobMatch/fo?_fo2257=== PAUSE TestGlobMatch/fo?_fo2258=== RUN TestGlobMatch/fo?_fooo2259=== PAUSE TestGlobMatch/fo?_fooo2260=== RUN TestGlobMatch/?oo_foo2261=== PAUSE TestGlobMatch/?oo_foo2262=== RUN TestGlobMatch/?oo_boo2263=== PAUSE TestGlobMatch/?oo_boo2264=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2265=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2266=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2267=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2268=== CONT TestValidateToken_KubernetesIssuerFromOwnToken22692026/09/20 10:38:33 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:54813/oidc22702026/09/20 10:38:33 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:54817/oidc22712026/09/20 10:38:33 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:54809/oidc22722026/09/20 10:38:33 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:54810/oidc22732026/09/20 10:38:33 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:54812/oidc22742026/09/20 10:38:33 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC12322752026/09/20 10:38:33 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:54815/oidc22762026/09/20 10:38:33 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:54814/oidc2277--- PASS: TestValidateToken_NoMatchingProvider (0.01s)2278=== CONT TestScopes_Rules22792026/09/20 10:38:33 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:54811/oidc2280--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.01s)2281=== CONT TestValidateToken_KubernetesServiceAccount22822026/09/20 10:38:33 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:54818/oidc2283--- PASS: TestValidateToken_BoundClaimsMismatch (0.01s)2284=== CONT TestScopes_ConfigValidation2285--- PASS: TestValidateToken_Expired (0.01s)2286=== CONT TestGlobMatch/fo?_fo2287=== CONT TestGlobMatch/foo_foo2288--- PASS: TestValidateToken_WrongAudience (0.01s)2289=== CONT TestGlobMatch/refs/*/main_refs/heads/main2290=== CONT TestGlobMatch/fo?_foo2291=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02292=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2293=== CONT TestGlobMatch/*/*_foo2294=== CONT TestGlobMatch/*/*_foo/bar2295=== CONT TestGlobMatch/foo*bar_foobarbaz2296=== CONT TestGlobMatch/foo*bar_foo123bar2297=== CONT TestGlobMatch/*bar_foo2298=== CONT TestGlobMatch/*bar_foobar2299=== CONT TestGlobMatch/*bar_bar2300=== CONT TestGlobMatch/foo*_bar2301=== CONT TestGlobMatch/foo*_foobar2302=== CONT TestGlobMatch/foo*_foo2303=== CONT TestGlobMatch/*_anything2304=== CONT TestGlobMatch/*_2305=== CONT TestGlobMatch/foo_bar2306=== CONT TestGlobMatch/foo*bar_foobar2307=== CONT TestGlobMatch/?oo_boo2308=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2309=== CONT TestGlobMatch/?oo_foo2310=== CONT TestGlobMatch/fo?_fooo2311=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2312--- PASS: TestGlobMatch (0.00s)2313 --- PASS: TestGlobMatch/fo?_fo (0.00s)2314 --- PASS: TestGlobMatch/foo_foo (0.00s)2315 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2316 --- PASS: TestGlobMatch/fo?_foo (0.00s)2317 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2318 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2319 --- PASS: TestGlobMatch/*/*_foo (0.00s)2320 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2321 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2322 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2323 --- PASS: TestGlobMatch/*bar_foo (0.00s)2324 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2325 --- PASS: TestGlobMatch/*bar_bar (0.00s)2326 --- PASS: TestGlobMatch/foo*_bar (0.00s)2327 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2328 --- PASS: TestGlobMatch/foo*_foo (0.00s)2329 --- PASS: TestGlobMatch/*_anything (0.00s)2330 --- PASS: TestGlobMatch/*_ (0.00s)2331 --- PASS: TestGlobMatch/foo_bar (0.00s)2332 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2333 --- PAS2026/09/20 10:38:33 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:54831/oidc2334S: TestGlobMatch/?oo_boo (0.00s)2335 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2336 --- PASS: TestGlobMatch/?oo_foo (0.00s)2337 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2338 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2339--- PASS: TestValidateToken_ValidToken (0.01s)2340--- PASS: TestScopes_ConfigValidation (0.00s)2341--- PASS: TestValidateToken_BoundSubjectMismatch (0.01s)2342--- PASS: TestValidateToken_MultipleProviders (0.01s)2343--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.01s)23442026/09/20 10:38:33 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:5483423452026/09/20 10:38:33 http: TLS handshake error from 127.0.0.1:54827: remote error: tls: bad certificate2346--- PASS: TestNewValidator_KubernetesRequiresCA (0.01s)2347--- PASS: TestValidateToken_KubernetesServiceAccount (0.01s)2348--- PASS: TestScopes_Rules (0.01s)2349PASS2350Running hook tests...2351=== RUN TestSendPathsEmpty2352=== PAUSE TestSendPathsEmpty2353=== RUN TestQueueEnqueueAndFetch2354=== PAUSE TestQueueEnqueueAndFetch2355=== RUN TestQueueDeduplication2356=== PAUSE TestQueueDeduplication2357=== RUN TestQueueRemove2358=== PAUSE TestQueueRemove2359=== RUN TestQueueFetchBatchLimit2360=== PAUSE TestQueueFetchBatchLimit2361=== RUN TestQueueRetryMovesToBack2362=== PAUSE TestQueueRetryMovesToBack2363=== RUN TestQueueFetchRemoveLifecycle2364=== PAUSE TestQueueFetchRemoveLifecycle2365=== RUN TestQueueConcurrentWriters2366=== PAUSE TestQueueConcurrentWriters2367=== RUN TestQueueRemoveLargeClosure2368=== PAUSE TestQueueRemoveLargeClosure2369=== RUN TestServerClientIntegration2370=== PAUSE TestServerClientIntegration2371=== RUN TestServerQueueError2372=== PAUSE TestServerQueueError2373=== RUN TestGetListenerSocketActivation2374 server_test.go:210: === RUN TestGetListenerSocketActivation2375 --- PASS: TestGetListenerSocketActivation (0.00s)2376 PASS2377 2378--- PASS: TestGetListenerSocketActivation (0.02s)2379=== RUN TestDrainIsolatesPoisonPath2380=== PAUSE TestDrainIsolatesPoisonPath2381=== RUN TestRunNotBlockedByPoisonHead2382=== PAUSE TestRunNotBlockedByPoisonHead2383=== RUN TestDrainGivesUpWhenServerDown2384=== PAUSE TestDrainGivesUpWhenServerDown2385=== RUN TestFailedPathPrunedByLaterClosure2386=== PAUSE TestFailedPathPrunedByLaterClosure2387=== RUN TestWorkerUploadsAndRemoves2388=== PAUSE TestWorkerUploadsAndRemoves2389=== RUN TestWorkerSkipsGCdPaths2390=== PAUSE TestWorkerSkipsGCdPaths2391=== RUN TestWorkerPrunesClosureDeps2392=== PAUSE TestWorkerPrunesClosureDeps2393=== RUN TestDrainTimeout2394=== PAUSE TestDrainTimeout2395=== CONT TestSendPathsEmpty2396=== CONT TestServerQueueError2397--- PASS: TestSendPathsEmpty (0.00s)2398=== CONT TestQueueFetchBatchLimit2399=== CONT TestQueueRemove2400=== CONT TestQueueDeduplication2401=== CONT TestQueueRetryMovesToBack2402=== CONT TestQueueEnqueueAndFetch2403=== CONT TestServerClientIntegration2404=== CONT TestWorkerUploadsAndRemoves2405=== CONT TestDrainTimeout2406=== CONT TestWorkerPrunesClosureDeps24072026/09/20 10:38:33 ERROR Failed to queue paths error="permission denied" count=12408--- PASS: TestServerClientIntegration (0.00s)2409=== CONT TestWorkerSkipsGCdPaths2410--- PASS: TestServerQueueError (0.00s)2411=== CONT TestDrainGivesUpWhenServerDown24122026/09/20 10:38:33 INFO Upload queue status pending=22413--- PASS: TestQueueEnqueueAndFetch (0.01s)2414=== CONT TestFailedPathPrunedByLaterClosure24152026/09/20 10:38:33 INFO Uploading batch count=224162026/09/20 10:38:33 INFO Upload queue status pending=22417--- PASS: TestQueueDeduplication (0.01s)2418=== CONT TestRunNotBlockedByPoisonHead24192026/09/20 10:38:33 INFO Uploading batch count=124202026/09/20 10:38:33 INFO Upload queue status pending=224212026/09/20 10:38:33 WARN Store path no longer exists (garbage collected?), removing from queue path=/nix/var/nix/builds/nix-52094-4089225465/TestWorkerSkipsGCdPaths189357767/002/nonexistent2422--- PASS: TestQueueRetryMovesToBack (0.01s)2423=== CONT TestQueueConcurrentWriters24242026/09/20 10:38:33 INFO Uploading batch count=124252026/09/20 10:38:33 INFO Uploading batch count=224262026/09/20 10:38:33 ERROR Upload failed error="upload failed" count=224272026/09/20 10:38:33 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-52094-4089225465/TestDrainGivesUpWhenServerDown8709471/002/a24282026/09/20 10:38:33 INFO Uploading batch count=22429--- PASS: TestQueueRemove (0.01s)2430=== CONT TestQueueFetchRemoveLifecycle2431--- PASS: TestQueueFetchBatchLimit (0.01s)2432=== CONT TestDrainIsolatesPoisonPath24332026/09/20 10:38:33 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-52094-4089225465/TestDrainGivesUpWhenServerDown8709471/002/b24342026/09/20 10:38:33 INFO Uploading batch count=124352026/09/20 10:38:33 ERROR Upload failed error="upload failed" count=124362026/09/20 10:38:33 INFO Uploading batch count=224372026/09/20 10:38:33 ERROR Upload failed error="upload failed" count=224382026/09/20 10:38:33 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-52094-4089225465/TestDrainGivesUpWhenServerDown8709471/002/c24392026/09/20 10:38:33 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-52094-4089225465/TestDrainGivesUpWhenServerDown8709471/002/d24402026/09/20 10:38:33 INFO Uploading batch count=124412026/09/20 10:38:33 INFO Uploading batch count=124422026/09/20 10:38:33 INFO Uploading batch count=224432026/09/20 10:38:33 ERROR Upload failed error="upload failed" count=224442026/09/20 10:38:33 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-52094-4089225465/TestDrainGivesUpWhenServerDown8709471/002/e24452026/09/20 10:38:33 INFO Upload queue status pending=324462026/09/20 10:38:33 INFO Uploading batch count=124472026/09/20 10:38:33 ERROR Upload failed error="upload failed" count=124482026/09/20 10:38:33 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-52094-4089225465/TestDrainGivesUpWhenServerDown8709471/002/f24492026/09/20 10:38:33 ERROR Drain finished with paths left in queue remaining=102450--- PASS: TestFailedPathPrunedByLaterClosure (0.00s)2451=== CONT TestQueueRemoveLargeClosure2452--- PASS: TestDrainGivesUpWhenServerDown (0.01s)24532026/09/20 10:38:33 INFO Uploading batch count=424542026/09/20 10:38:33 ERROR Upload failed error="upload failed" count=424552026/09/20 10:38:33 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-52094-4089225465/TestDrainIsolatesPoisonPath542651134/002/bbb2456--- PASS: TestQueueFetchRemoveLifecycle (0.00s)24572026/09/20 10:38:33 INFO Uploading batch count=124582026/09/20 10:38:33 ERROR Upload failed error="upload failed" count=124592026/09/20 10:38:33 INFO Uploading batch count=124602026/09/20 10:38:33 ERROR Upload failed error="upload failed" count=124612026/09/20 10:38:33 INFO Uploading batch count=124622026/09/20 10:38:33 ERROR Upload failed error="upload failed" count=124632026/09/20 10:38:33 ERROR Drain finished with paths left in queue remaining=12464--- PASS: TestDrainIsolatesPoisonPath (0.00s)2465--- PASS: TestWorkerUploadsAndRemoves (0.03s)2466--- PASS: TestWorkerSkipsGCdPaths (0.03s)2467--- PASS: TestWorkerPrunesClosureDeps (0.03s)2468--- PASS: TestQueueRemoveLargeClosure (0.04s)2469--- PASS: TestQueueConcurrentWriters (0.14s)24702026/09/20 10:38:33 ERROR Upload failed error="context deadline exceeded" count=224712026/09/20 10:38:33 ERROR Drain finished with paths left in queue remaining=42472--- PASS: TestDrainTimeout (0.21s)24732026/09/20 10:38:34 INFO Uploading batch count=124742026/09/20 10:38:34 INFO Uploading batch count=124752026/09/20 10:38:34 INFO Uploading batch count=124762026/09/20 10:38:34 ERROR Upload failed error="upload failed" count=124772026/09/20 10:38:34 INFO Uploading batch count=124782026/09/20 10:38:34 ERROR Upload failed error="upload failed" count=124792026/09/20 10:38:34 INFO Uploading batch count=124802026/09/20 10:38:34 ERROR Upload failed error="upload failed" count=124812026/09/20 10:38:34 INFO Uploading batch count=124822026/09/20 10:38:34 ERROR Upload failed error="upload failed" count=124832026/09/20 10:38:34 ERROR Drain finished with paths left in queue remaining=12484--- PASS: TestRunNotBlockedByPoisonHead (1.02s)2485PASS