niks3-go-unit-tests
checks.aarch64-darwin.go-unit-tests
· build #231
· 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 (1.15s)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 TestStaticToken90--- PASS: TestStaticToken (0.00s)91=== CONT TestStreamPushReportsEveryPath92=== CONT TestShellSplit93=== CONT TestSetClientTLSErrors94=== CONT TestSetClientTLSDoesNotMutateDefaultTransport95--- PASS: TestShellSplit (0.00s)96=== CONT TestShellSplitErrors97--- PASS: TestShellSplitErrors (0.00s)98=== CONT TestConvertHashToNix3299=== CONT TestSetClientTLS100=== RUN TestConvertHashToNix32/SRI_format_to_Nix32101=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32102=== RUN TestConvertHashToNix32/already_Nix32_format103=== PAUSE TestConvertHashToNix32/already_Nix32_format104=== RUN TestConvertHashToNix32/invalid_format105=== PAUSE TestConvertHashToNix32/invalid_format106=== CONT TestDoWithRetry_BodyReplayedViaGetBody107=== CONT TestStreamPushRequestLine108=== CONT TestStreamPushGivesUpOnDeadServer109=== CONT TestStreamPushIsolatesFailures110=== CONT TestStreamPushBatchesUnderLoad1112026/09/21 12:57:02 ERROR Upload failed error="bad path" count=31122026/09/21 12:57:02 ERROR Upload failed error="connection refused" count=201132026/09/21 12:57:02 ERROR Server seems unavailable, giving up on batch untried=17114--- PASS: TestStreamPushReportsEveryPath (0.00s)115=== CONT TestResolveStorePath116--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)117=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess1182026/09/21 12:57:02 WARN Rate limiter enabled after throttle name=server-test rate=51192026/09/21 12:57:02 ERROR Upload failed error=boom count=1120--- PASS: TestStreamPushIsolatesFailures (0.00s)121=== CONT TestRateLimiterFeedback122=== RUN TestRateLimiterFeedback/429_enables_limiter123=== PAUSE TestRateLimiterFeedback/429_enables_limiter124=== RUN TestRateLimiterFeedback/503_enables_limiter125=== PAUSE TestRateLimiterFeedback/503_enables_limiter126=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter127=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter128=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter129=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter130=== CONT TestPathInfoCACompatibility131=== RUN TestPathInfoCACompatibility/null_ca_field132=== PAUSE TestPathInfoCACompatibility/null_ca_field133=== RUN TestPathInfoCACompatibility/old_string_format_-_text134=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text135=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive136=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive137=== RUN TestPathInfoCACompatibility/new_structured_format_-_text138=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text139=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method140=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method141=== CONT TestParsePathInfoJSONMultiplePaths142=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths143=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths144=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths145=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths146=== CONT TestParsePathInfoJSON147=== RUN TestParsePathInfoJSON/Nix_format148=== PAUSE TestParsePathInfoJSON/Nix_format149=== RUN TestParsePathInfoJSON/Lix_format150=== PAUSE TestParsePathInfoJSON/Lix_format151=== RUN TestParsePathInfoJSON/empty_input152=== PAUSE TestParsePathInfoJSON/empty_input153=== RUN TestParsePathInfoJSON/whitespace_only154=== PAUSE TestParsePathInfoJSON/whitespace_only155=== RUN TestParsePathInfoJSON/invalid_JSON156=== PAUSE TestParsePathInfoJSON/invalid_JSON157=== CONT TestPathInfoHashCompatibility158=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)159=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)160=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon161=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon162=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI163=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI164=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512165=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512166=== CONT TestGetStorePathHash167=== RUN TestGetStorePathHash/valid_store_path168=== PAUSE TestGetStorePathHash/valid_store_path169=== RUN TestGetStorePathHash/basename_without_hyphen_should_error170=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error171=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error172=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error173=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error174=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error175=== CONT TestDumpPathMatchesNix1762026/09/21 12:57:02 WARN Rate limiter enabled after throttle name=server-test rate=51772026/09/21 12:57:02 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:570061782026/09/21 12:57:02 WARN Rate limiter backed off name=server-test rate=51792026/09/21 12:57:02 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:57006180=== RUN TestSetClientTLSErrors/missing_cert_file181--- PASS: TestDoServerRequestAttachesToken (0.01s)182=== PAUSE TestSetClientTLSErrors/missing_cert_file183=== RUN TestSetClientTLSErrors/missing_key_file184=== CONT TestEncodeNixBase32WithRealHash185=== PAUSE TestSetClientTLSErrors/missing_key_file186=== RUN TestSetClientTLSErrors/missing_ca_file187=== PAUSE TestSetClientTLSErrors/missing_ca_file188--- PASS: TestEncodeNixBase32WithRealHash (0.00s)189=== CONT TestEncodeNixBase32190=== RUN TestEncodeNixBase32/test_string_hash191--- PASS: TestResolveStorePath (0.00s)192=== PAUSE TestEncodeNixBase32/test_string_hash193=== RUN TestEncodeNixBase32/empty_input194=== RUN TestSetClientTLSErrors/invalid_ca_file195--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.00s)196=== CONT TestDumpPathWriterError197=== PAUSE TestEncodeNixBase32/empty_input198=== CONT TestDumpPathSingleFile199=== PAUSE TestSetClientTLSErrors/invalid_ca_file200=== CONT TestScriptTokenCachesUntilRefresh201=== CONT TestFileTokenMissing202--- PASS: TestFileTokenMissing (0.00s)203=== CONT TestScriptTokenEmptyCommand204--- PASS: TestScriptTokenEmptyCommand (0.00s)205=== CONT TestFilterOversizedClosures206=== RUN TestFilterOversizedClosures/no_limit_keeps_everything207=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything208=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped209=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped210=== RUN TestFilterOversizedClosures/all_closures_skipped211=== PAUSE TestFilterOversizedClosures/all_closures_skipped212=== CONT TestUploadMultipart_SupersededByPeer213=== RUN TestUploadMultipart_SupersededByPeer/exists214=== PAUSE TestUploadMultipart_SupersededByPeer/exists215=== RUN TestUploadMultipart_SupersededByPeer/missing216=== PAUSE TestUploadMultipart_SupersededByPeer/missing217=== CONT TestPartSizeForNAR218=== RUN TestPartSizeForNAR/zero_stays_at_minimum219=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum220=== RUN TestPartSizeForNAR/small_stays_at_minimum221=== PAUSE TestPartSizeForNAR/small_stays_at_minimum222=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum223=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum224--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.01s)225=== CONT TestCaseHackSuffix226=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts227=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts228=== RUN TestSetClientTLS/rejects_connection_without_client_cert229=== RUN TestPartSizeForNAR/1_TiB230=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert231=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA232=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA233=== RUN TestSetClientTLS/preserves_debug_logging_transport234=== PAUSE TestSetClientTLS/preserves_debug_logging_transport235=== CONT TestScriptTokenBadJSON236=== PAUSE TestPartSizeForNAR/1_TiB237=== RUN TestPartSizeForNAR/5_TiB_S3_max_object238=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object239=== RUN TestPartSizeForNAR/capped_at_5_GiB240=== PAUSE TestPartSizeForNAR/capped_at_5_GiB241=== CONT TestScriptTokenScriptFails242--- PASS: TestScriptTokenScriptFails (0.01s)243=== CONT TestFileTokenEmpty244--- PASS: TestFileTokenEmpty (0.00s)245=== CONT TestScriptTokenNoExpiryRerunsEveryCall246--- PASS: TestStreamPushRequestLine (0.02s)247=== CONT TestRegisterUploadedObjectReusesConnections248=== CONT TestScriptTokenEmptyToken249--- PASS: TestScriptTokenBadJSON (0.01s)250--- PASS: TestScriptTokenEmptyToken (0.02s)251=== CONT TestFileTokenReadsAndCaches252--- PASS: TestFileTokenReadsAndCaches (0.00s)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 TestRateLimiterFeedback/429_enables_limiter2612026/09/21 12:57:02 WARN Rate limiter enabled after throttle name=server-test rate=52622026/09/21 12:57:02 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:570772632026/09/21 12:57:02 WARN Rate limiter backed off name=server-test rate=5264=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter265=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter266--- PASS: TestScriptTokenCachesUntilRefresh (0.05s)267=== CONT TestRateLimiterFeedback/503_enables_limiter268=== CONT TestPathInfoCACompatibility/null_ca_field269=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths270=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method271=== CONT TestPathInfoCACompatibility/new_structured_format_-_text272=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive273=== CONT TestPathInfoCACompatibility/old_string_format_-_text274--- PASS: TestPathInfoCACompatibility (0.00s)275 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)276 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)277 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)278 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)279 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)280=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths281--- PASS: TestParsePathInfoJSONMultiplePaths (0.00s)282 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)283 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)284=== CONT TestParsePathInfoJSON/Nix_format285=== CONT TestParsePathInfoJSON/whitespace_only286=== CONT TestParsePathInfoJSON/invalid_JSON287=== CONT TestParsePathInfoJSON/empty_input288=== CONT TestParsePathInfoJSON/Lix_format289--- PASS: TestParsePathInfoJSON (0.00s)290 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)291 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)292 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)293 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)294 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)295=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)296=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI297=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512298=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon299--- PASS: TestPathInfoHashCompatibility (0.00s)300 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)301 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)302 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)303 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)304=== CONT TestGetStorePathHash/valid_store_path305=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error306=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error307=== CONT TestGetStorePathHash/basename_without_hyphen_should_error308--- PASS: TestGetStorePathHash (0.00s)309 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)310 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)311 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)312 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)313=== CONT TestEncodeNixBase32/test_string_hash314=== CONT TestEncodeNixBase32/empty_input3152026/09/21 12:57:02 WARN Rate limiter enabled after throttle name=server-test rate=5316--- PASS: TestEncodeNixBase32 (0.00s)317 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)318 --- PASS: TestEncodeNixBase32/empty_input (0.00s)319=== CONT TestSetClientTLSErrors/missing_cert_file3202026/09/21 12:57:02 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:57083321=== CONT TestSetClientTLSErrors/invalid_ca_file322=== CONT TestSetClientTLSErrors/missing_ca_file323=== CONT TestSetClientTLSErrors/missing_key_file3242026/09/21 12:57:02 WARN Rate limiter backed off name=server-test rate=5325--- PASS: TestRateLimiterFeedback (0.00s)326 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)327 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)328 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)329 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)330=== CONT TestUploadMultipart_SupersededByPeer/exists331=== CONT TestFilterOversizedClosures/no_limit_keeps_everything332=== CONT TestFilterOversizedClosures/all_closures_skipped3332026/09/21 12:57:02 WARN Skipping closure: path exceeds server max NAR size top_level_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper oversized_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper nar_size=100 max_nar_size=50334=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped3352026/09/21 12:57:02 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=2000336--- PASS: TestFilterOversizedClosures (0.00s)337 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)338 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)339 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)340=== CONT TestUploadMultipart_SupersededByPeer/missing341--- PASS: TestSetClientTLSErrors (0.01s)342 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)343 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)344 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)345 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)346=== CONT TestSetClientTLS/rejects_connection_without_client_cert347--- PASS: TestUploadMultipart_SupersededByPeer (0.00s)348 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)349 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.01s)350=== CONT TestSetClientTLS/preserves_debug_logging_transport351=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA352=== CONT TestPartSizeForNAR/zero_stays_at_minimum353=== CONT TestPartSizeForNAR/capped_at_5_GiB354=== CONT TestPartSizeForNAR/5_TiB_S3_max_object355=== CONT TestPartSizeForNAR/1_TiB356=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts357=== CONT TestPartSizeForNAR/small_stays_at_minimum358=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum359--- PASS: TestPartSizeForNAR (0.00s)360 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)361 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)362 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)363 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)364 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)365 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)366 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)3672026/09/21 12:57:02 http: TLS handshake error from 127.0.0.1:57088: remote error: tls: bad certificate368--- PASS: TestSetClientTLS (0.01s)369 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.01s)370 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.00s)371 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.02s)372--- PASS: TestRegisterUploadedObjectReusesConnections (0.06s)373--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.06s)374--- PASS: TestDumpPathWriterError (0.08s)375--- PASS: TestStreamPushBatchesUnderLoad (0.10s)376--- PASS: TestCaseHackSuffix (0.11s)377--- PASS: TestDumpPathSingleFile (0.17s)378--- PASS: TestDumpPathMatchesNix (0.23s)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-14861-3745989896/postgres3678843660/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-14861-3745989896/postgres3678843660/data -l logfile start4084092026-09-21 12:57:07.614 UTC [16831] LOG: starting PostgreSQL 18.6 on aarch64-apple-darwin25.6.0, compiled by clang version 21.1.8, 64-bit4102026-09-21 12:57:07.614 UTC [16831] LOG: listening on Unix socket "/nix/var/nix/builds/nix-14861-3745989896/postgres3678843660/.s.PGSQL.5432"4112026-09-21 12:57:07.626 UTC [16838] LOG: database system was shut down at 2026-09-21 12:57:07 UTC4122026-09-21 12:57:07.627 UTC [16831] LOG: database system is ready to accept connections413/nix/var/nix/builds/nix-14861-3745989896/postgres3678843660:5432 - accepting connections414=== RUN TestService_AuthMiddleware415=== PAUSE TestService_AuthMiddleware416=== RUN TestService_AuthMiddleware_MTLSProxyHeader417=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader418=== RUN TestService_AuthMiddleware_MTLSBoundSubjects419=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects420=== RUN TestService_ReadAuthMiddleware421=== PAUSE TestService_ReadAuthMiddleware422=== RUN TestService_AuthMiddleware_OIDC423=== PAUSE TestService_AuthMiddleware_OIDC424=== RUN TestService_RequireScope_OIDC425=== PAUSE TestService_RequireScope_OIDC426=== RUN TestService_ReadScope_PublicByDefault427=== PAUSE TestService_ReadScope_PublicByDefault428=== RUN TestCacheConfigHandler429=== PAUSE TestCacheConfigHandler430=== RUN TestCacheStatsHandler431=== PAUSE TestCacheStatsHandler432=== RUN TestClientCADerivations433=== PAUSE TestClientCADerivations434=== RUN TestClientErrorHandling435=== PAUSE TestClientErrorHandling436=== RUN TestClientIntegration437=== PAUSE TestClientIntegration438=== RUN TestClientMultipleUploads439=== PAUSE TestClientMultipleUploads440=== RUN TestClientWithDependencies441=== PAUSE TestClientWithDependencies442=== RUN TestClientSharedPathCommittedMidPush443=== PAUSE TestClientSharedPathCommittedMidPush444=== RUN TestPinProtectsFromGC445=== PAUSE TestPinProtectsFromGC446=== RUN TestResolveDBConnectionString447=== PAUSE TestResolveDBConnectionString448=== RUN TestLeadElectsOneAndHandsOver449=== PAUSE TestLeadElectsOneAndHandsOver450=== RUN TestLeadEndsOnShutdown451=== PAUSE TestLeadEndsOnShutdown452=== RUN TestGCAdvisoryLockBlocksConcurrentRun4532026-09-21 12:57:11.513 UTC [17005] ERROR: relation "goose_db_version" does not exist at character 364542026-09-21 12:57:11.513 UTC [17005] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC4552026/09/21 12:57:11 OK 20241026095416_initial_model.sql (7.21ms)4562026/09/21 12:57:11 OK 20251210153512_drop_unused_gin_index.sql (1.12ms)4572026/09/21 12:57:11 OK 20251218171726_add_pins.sql (2.65ms)4582026/09/21 12:57:11 OK 20260628120000_add_object_size_and_stats.sql (2.69ms)4592026/09/21 12:57:11 OK 20260905000000_add_claims.sql (3.59ms)4602026/09/21 12:57:11 OK 20260920000000_drop_claims.sql (1.9ms)4612026/09/21 12:57:11 goose: successfully migrated database to version: 202609200000004622026/09/21 12:57:11 OK 1_commit_pending_closure.sql (2.27ms)4632026/09/21 12:57:11 OK 2_object_stats_trigger.sql (651.33µs)4642026/09/21 12:57:11 goose: up to current file version: 2465--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.49s)466=== RUN TestGCBugBareHashReferences467=== PAUSE TestGCBugBareHashReferences468=== RUN TestGCMetrics469=== PAUSE TestGCMetrics470=== RUN TestGCTaskStore_StartNew471=== PAUSE TestGCTaskStore_StartNew472=== RUN TestGCTaskStore_DeduplicateSameParams473=== PAUSE TestGCTaskStore_DeduplicateSameParams474=== RUN TestGCTaskStore_ConflictDifferentParams475=== PAUSE TestGCTaskStore_ConflictDifferentParams476=== RUN TestGCTaskStore_GetEmpty477=== PAUSE TestGCTaskStore_GetEmpty478=== RUN TestGCTaskStore_GetReturnsLatest479=== PAUSE TestGCTaskStore_GetReturnsLatest480=== RUN TestGCTaskStore_CompletedAllowsNewTask481=== PAUSE TestGCTaskStore_CompletedAllowsNewTask482=== RUN TestGCTaskStore_PhaseUpdates483=== PAUSE TestGCTaskStore_PhaseUpdates484=== RUN TestGCTaskStore_Fail485=== PAUSE TestGCTaskStore_Fail486=== RUN TestGracefulShutdownDrainsInflight487=== PAUSE TestGracefulShutdownDrainsInflight488=== RUN TestService_healthCheckHandler489=== PAUSE TestService_healthCheckHandler490=== RUN TestService_readinessHandler491=== PAUSE TestService_readinessHandler492=== RUN TestGenerateLandingPage493=== PAUSE TestGenerateLandingPage494=== RUN TestCacheConfigHandlerMaxNarSize495=== PAUSE TestCacheConfigHandlerMaxNarSize496=== RUN TestCreatePendingClosureRejectsOversizedNAR497=== PAUSE TestCreatePendingClosureRejectsOversizedNAR498=== RUN TestNARDeduplicationMetadataUploadBug499=== PAUSE TestNARDeduplicationMetadataUploadBug500=== RUN TestMetricsInventory501=== PAUSE TestMetricsInventory502=== RUN TestService_NativeMTLS503=== PAUSE TestService_NativeMTLS504=== RUN TestServerTLSConfig505=== PAUSE TestServerTLSConfig506=== RUN TestMultipartCleanup507=== PAUSE TestMultipartCleanup508=== RUN TestObjectStatsTrigger509=== PAUSE TestObjectStatsTrigger510=== RUN TestOrphanedObjectsGC511=== PAUSE TestOrphanedObjectsGC512=== RUN TestOrphanedObjectsGCStressTest513=== PAUSE TestOrphanedObjectsGCStressTest514=== RUN TestResurrectedObjectNotDeleted515=== PAUSE TestResurrectedObjectNotDeleted516=== RUN TestParseSingleRange517=== PAUSE TestParseSingleRange518=== RUN TestIsValidCachePath519=== PAUSE TestIsValidCachePath520=== RUN TestReadProxyNarinfo521=== PAUSE TestReadProxyNarinfo522=== RUN TestReadProxyNarinfoAlreadyDecompressed523=== PAUSE TestReadProxyNarinfoAlreadyDecompressed524=== RUN TestReadProxyNarStreaming525=== PAUSE TestReadProxyNarStreaming526=== RUN TestReadProxy404527=== PAUSE TestReadProxy404528=== RUN TestReadProxyInvalidPath529=== PAUSE TestReadProxyInvalidPath530=== RUN TestReadProxyHead531=== PAUSE TestReadProxyHead532=== RUN TestReadProxyConditionalGet533=== PAUSE TestReadProxyConditionalGet534=== RUN TestReadProxyRootRedirectsToIndexHTML535=== PAUSE TestReadProxyRootRedirectsToIndexHTML536=== RUN TestReadProxyDisabled537=== PAUSE TestReadProxyDisabled538=== RUN TestReadRedirectNar539=== PAUSE TestReadRedirectNar540=== RUN TestReadRedirectKeepsNarinfoProxied541=== PAUSE TestReadRedirectKeepsNarinfoProxied542=== RUN TestReadProxyRangeRequest543=== PAUSE TestReadProxyRangeRequest544=== RUN TestReadRedirectUsesPublicS3URL545=== PAUSE TestReadRedirectUsesPublicS3URL546=== RUN TestRedundantMultipartUpload547=== PAUSE TestRedundantMultipartUpload548=== RUN TestCompleteMultipartUpload_ErrorButObjectExists549=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists550=== RUN TestCompletedNarNotReofferedAcrossClosures551=== PAUSE TestCompletedNarNotReofferedAcrossClosures552=== RUN TestPresignedUploadRegisteredBeforeCommit553=== PAUSE TestPresignedUploadRegisteredBeforeCommit554=== RUN TestService_Rustfstest555=== PAUSE TestService_Rustfstest556=== RUN TestParseSize557=== PAUSE TestParseSize558=== RUN TestSkippedUploadsHandler559=== PAUSE TestSkippedUploadsHandler560=== RUN TestSystemdListenerNotActivated561--- PASS: TestSystemdListenerNotActivated (0.00s)562=== RUN TestWatchdogBeatsWhenHealthy563--- PASS: TestWatchdogBeatsWhenHealthy (0.03s)564=== RUN TestWatchdogSkipsWhenUnhealthy5652026/09/21 12:57:11 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5662026/09/21 12:57:11 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5672026/09/21 12:57:11 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5682026/09/21 12:57:11 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5692026/09/21 12:57:11 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5702026/09/21 12:57:11 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5712026/09/21 12:57:11 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5722026/09/21 12:57:11 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5732026/09/21 12:57:11 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5742026/09/21 12:57:11 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"575--- PASS: TestWatchdogSkipsWhenUnhealthy (0.21s)576=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle577=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle578=== RUN TestProxyWriteTimeout579=== PAUSE TestProxyWriteTimeout580=== RUN TestIsValidUploadKey581=== PAUSE TestIsValidUploadKey582=== RUN TestUploadHandlersRejectInvalidKeys583=== PAUSE TestUploadHandlersRejectInvalidKeys584=== RUN TestUploadHandlersRejectOversizedBody585=== PAUSE TestUploadHandlersRejectOversizedBody586=== RUN TestService_cleanupPendingClosuresHandler587=== PAUSE TestService_cleanupPendingClosuresHandler588=== RUN TestService_createPendingClosureHandler589=== PAUSE TestService_createPendingClosureHandler590=== RUN TestService_verifyS3Integrity591=== PAUSE TestService_verifyS3Integrity592=== RUN TestCompleteMultipartUnregistered593=== PAUSE TestCompleteMultipartUnregistered594=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT595=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT596=== CONT TestService_AuthMiddleware597=== CONT TestReadRedirectUsesPublicS3URL598=== CONT TestProxyWriteTimeout599=== RUN TestProxyWriteTimeout/narinfo600=== PAUSE TestProxyWriteTimeout/narinfo601=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT602=== CONT TestCompleteMultipartUnregistered603=== CONT TestService_verifyS3Integrity604=== CONT TestService_createPendingClosureHandler605=== CONT TestService_cleanupPendingClosuresHandler606=== CONT TestUploadHandlersRejectOversizedBody607=== CONT TestUploadHandlersRejectInvalidKeys608=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info609=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info610=== RUN TestProxyWriteTimeout/1_GiB_nar611=== PAUSE TestProxyWriteTimeout/1_GiB_nar612=== RUN TestProxyWriteTimeout/10_GiB_nar613=== PAUSE TestProxyWriteTimeout/10_GiB_nar614=== RUN TestProxyWriteTimeout/unknown_size615=== PAUSE TestProxyWriteTimeout/unknown_size616=== CONT TestIsValidUploadKey617=== RUN TestIsValidUploadKey/narinfo618=== PAUSE TestIsValidUploadKey/narinfo619=== RUN TestIsValidUploadKey/nar_zst620=== PAUSE TestIsValidUploadKey/nar_zst621=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal622=== RUN TestIsValidUploadKey/nar_xz623=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal624=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key625=== PAUSE TestIsValidUploadKey/nar_xz626=== RUN TestIsValidUploadKey/nar_plain627=== PAUSE TestIsValidUploadKey/nar_plain628=== RUN TestIsValidUploadKey/listing629=== PAUSE TestIsValidUploadKey/listing630=== RUN TestIsValidUploadKey/build_log631=== PAUSE TestIsValidUploadKey/build_log632=== RUN TestIsValidUploadKey/build_log_home-manager_file633=== PAUSE TestIsValidUploadKey/build_log_home-manager_file634=== RUN TestIsValidUploadKey/build_log_plus_in_name635=== PAUSE TestIsValidUploadKey/build_log_plus_in_name636=== RUN TestIsValidUploadKey/build_log_question_mark637=== PAUSE TestIsValidUploadKey/build_log_question_mark638=== RUN TestIsValidUploadKey/build_log_equals639=== PAUSE TestIsValidUploadKey/build_log_equals640=== RUN TestIsValidUploadKey/realisation641=== PAUSE TestIsValidUploadKey/realisation642=== RUN TestIsValidUploadKey/realisation_plus_in_output643=== PAUSE TestIsValidUploadKey/realisation_plus_in_output644=== RUN TestIsValidUploadKey/nix-cache-info645=== PAUSE TestIsValidUploadKey/nix-cache-info646=== RUN TestIsValidUploadKey/index.html647=== PAUSE TestIsValidUploadKey/index.html648=== RUN TestIsValidUploadKey/narinfo_key,_nar_type649=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type650=== RUN TestIsValidUploadKey/nar_key,_narinfo_type651=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type652=== RUN TestIsValidUploadKey/listing_key,_narinfo_type653=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type654=== RUN TestIsValidUploadKey/traversal655=== PAUSE TestIsValidUploadKey/traversal656=== RUN TestIsValidUploadKey/traversal_nar657=== PAUSE TestIsValidUploadKey/traversal_nar658=== RUN TestIsValidUploadKey/absolute659=== PAUSE TestIsValidUploadKey/absolute660=== RUN TestIsValidUploadKey/empty_key661=== PAUSE TestIsValidUploadKey/empty_key662=== RUN TestIsValidUploadKey/unknown_type663=== PAUSE TestIsValidUploadKey/unknown_type664=== CONT TestGracefulShutdownDrainsInflight665=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key666=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key667=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key668=== CONT TestReadProxyRangeRequest6692026/09/21 12:57:11 INFO Starting HTTP server address=127.0.0.1:571636702026/09/21 12:57:11 INFO Shutdown signal received, draining in-flight requests timeout=10s671=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts672=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts673=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure674=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure675=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart676=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart677=== CONT TestOrphanedObjectsGCStressTest678--- PASS: TestGracefulShutdownDrainsInflight (0.08s)679=== CONT TestOrphanedObjectsGC6802026-09-21 12:57:12.162 UTC [17231] ERROR: relation "goose_db_version" does not exist at character 366812026-09-21 12:57:12.162 UTC [17231] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6822026-09-21 12:57:12.169 UTC [17232] ERROR: relation "goose_db_version" does not exist at character 366832026-09-21 12:57:12.169 UTC [17232] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6842026-09-21 12:57:12.169 UTC [17233] ERROR: relation "goose_db_version" does not exist at character 366852026-09-21 12:57:12.169 UTC [17233] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6862026-09-21 12:57:12.169 UTC [17234] ERROR: relation "goose_db_version" does not exist at character 366872026-09-21 12:57:12.169 UTC [17234] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6882026-09-21 12:57:12.171 UTC [17235] ERROR: relation "goose_db_version" does not exist at character 366892026-09-21 12:57:12.171 UTC [17235] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6902026-09-21 12:57:12.173 UTC [17236] ERROR: relation "goose_db_version" does not exist at character 366912026-09-21 12:57:12.173 UTC [17236] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6922026-09-21 12:57:12.173 UTC [17237] ERROR: relation "goose_db_version" does not exist at character 366932026-09-21 12:57:12.173 UTC [17237] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6942026-09-21 12:57:12.174 UTC [17238] ERROR: relation "goose_db_version" does not exist at character 366952026-09-21 12:57:12.174 UTC [17238] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6962026-09-21 12:57:12.174 UTC [17239] ERROR: relation "goose_db_version" does not exist at character 366972026-09-21 12:57:12.174 UTC [17239] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6982026/09/21 12:57:12 OK 20241026095416_initial_model.sql (9ms)6992026/09/21 12:57:12 OK 20251210153512_drop_unused_gin_index.sql (6.47ms)7002026/09/21 12:57:12 OK 20251218171726_add_pins.sql (5.34ms)7012026/09/21 12:57:12 OK 20241026095416_initial_model.sql (18.16ms)7022026/09/21 12:57:12 OK 20241026095416_initial_model.sql (15.53ms)7032026/09/21 12:57:12 OK 20241026095416_initial_model.sql (19.06ms)7042026/09/21 12:57:12 OK 20241026095416_initial_model.sql (17.92ms)7052026/09/21 12:57:12 OK 20260628120000_add_object_size_and_stats.sql (3.68ms)7062026/09/21 12:57:12 OK 20241026095416_initial_model.sql (10.24ms)7072026/09/21 12:57:12 OK 20241026095416_initial_model.sql (20.02ms)7082026/09/21 12:57:12 OK 20251210153512_drop_unused_gin_index.sql (1.67ms)7092026/09/21 12:57:12 OK 20251210153512_drop_unused_gin_index.sql (1.24ms)7102026/09/21 12:57:12 OK 20251210153512_drop_unused_gin_index.sql (983.21µs)7112026/09/21 12:57:12 OK 20251210153512_drop_unused_gin_index.sql (2.4ms)7122026/09/21 12:57:12 OK 20251210153512_drop_unused_gin_index.sql (1.01ms)7132026/09/21 12:57:12 OK 20251210153512_drop_unused_gin_index.sql (2.3ms)7142026/09/21 12:57:12 OK 20241026095416_initial_model.sql (11.91ms)7152026/09/21 12:57:12 OK 20241026095416_initial_model.sql (12.5ms)7162026/09/21 12:57:12 OK 20251210153512_drop_unused_gin_index.sql (765.04µs)7172026/09/21 12:57:12 OK 20260905000000_add_claims.sql (2.93ms)7182026/09/21 12:57:12 OK 20251218171726_add_pins.sql (1.88ms)7192026/09/21 12:57:12 OK 20251210153512_drop_unused_gin_index.sql (763.92µs)7202026/09/21 12:57:12 OK 20251218171726_add_pins.sql (2.06ms)7212026/09/21 12:57:12 OK 20251218171726_add_pins.sql (2.43ms)7222026/09/21 12:57:12 OK 20251218171726_add_pins.sql (3.43ms)7232026/09/21 12:57:12 OK 20251218171726_add_pins.sql (2.6ms)7242026/09/21 12:57:12 OK 20251218171726_add_pins.sql (2.89ms)7252026/09/21 12:57:12 OK 20260920000000_drop_claims.sql (1.81ms)7262026/09/21 12:57:12 goose: successfully migrated database to version: 202609200000007272026/09/21 12:57:12 OK 20251218171726_add_pins.sql (1.93ms)7282026/09/21 12:57:12 OK 20260628120000_add_object_size_and_stats.sql (2.18ms)7292026/09/21 12:57:12 OK 20251218171726_add_pins.sql (2.39ms)7302026/09/21 12:57:12 OK 20260628120000_add_object_size_and_stats.sql (2.13ms)7312026/09/21 12:57:12 OK 20260628120000_add_object_size_and_stats.sql (2.5ms)7322026/09/21 12:57:12 OK 20260628120000_add_object_size_and_stats.sql (1.94ms)7332026/09/21 12:57:12 OK 20260628120000_add_object_size_and_stats.sql (2.38ms)7342026/09/21 12:57:12 OK 20260628120000_add_object_size_and_stats.sql (2.61ms)7352026/09/21 12:57:12 OK 1_commit_pending_closure.sql (2.49ms)7362026/09/21 12:57:12 OK 20260628120000_add_object_size_and_stats.sql (2.54ms)7372026/09/21 12:57:12 OK 20260628120000_add_object_size_and_stats.sql (2.36ms)7382026/09/21 12:57:12 OK 2_object_stats_trigger.sql (995.25µs)7392026/09/21 12:57:12 goose: up to current file version: 27402026/09/21 12:57:12 OK 20260905000000_add_claims.sql (3.34ms)7412026/09/21 12:57:12 OK 20260905000000_add_claims.sql (3.12ms)7422026/09/21 12:57:12 OK 20260905000000_add_claims.sql (3.16ms)7432026/09/21 12:57:12 OK 20260905000000_add_claims.sql (3.31ms)7442026/09/21 12:57:12 OK 20260905000000_add_claims.sql (3.26ms)7452026/09/21 12:57:12 OK 20260905000000_add_claims.sql (3.44ms)7462026/09/21 12:57:12 OK 20260905000000_add_claims.sql (2.89ms)7472026/09/21 12:57:12 OK 20260905000000_add_claims.sql (2.72ms)7482026/09/21 12:57:12 OK 20260920000000_drop_claims.sql (2.11ms)7492026/09/21 12:57:12 goose: successfully migrated database to version: 202609200000007502026/09/21 12:57:12 OK 20260920000000_drop_claims.sql (2.01ms)7512026/09/21 12:57:12 goose: successfully migrated database to version: 202609200000007522026/09/21 12:57:12 OK 20260920000000_drop_claims.sql (2.01ms)7532026/09/21 12:57:12 goose: successfully migrated database to version: 202609200000007542026/09/21 12:57:12 OK 20260920000000_drop_claims.sql (1.92ms)7552026/09/21 12:57:12 goose: successfully migrated database to version: 202609200000007562026/09/21 12:57:12 OK 20260920000000_drop_claims.sql (1.77ms)7572026/09/21 12:57:12 goose: successfully migrated database to version: 202609200000007582026/09/21 12:57:12 OK 20260920000000_drop_claims.sql (1.59ms)7592026/09/21 12:57:12 goose: successfully migrated database to version: 202609200000007602026/09/21 12:57:12 OK 1_commit_pending_closure.sql (1.8ms)7612026/09/21 12:57:12 OK 1_commit_pending_closure.sql (1.72ms)7622026/09/21 12:57:12 OK 1_commit_pending_closure.sql (1.65ms)7632026/09/21 12:57:12 OK 1_commit_pending_closure.sql (1.66ms)7642026/09/21 12:57:12 OK 1_commit_pending_closure.sql (1.5ms)7652026/09/21 12:57:12 OK 2_object_stats_trigger.sql (422.88µs)7662026/09/21 12:57:12 goose: up to current file version: 27672026/09/21 12:57:12 OK 2_object_stats_trigger.sql (493.33µs)7682026/09/21 12:57:12 goose: up to current file version: 27692026/09/21 12:57:12 OK 1_commit_pending_closure.sql (1.54ms)7702026/09/21 12:57:12 OK 2_object_stats_trigger.sql (555.04µs)7712026/09/21 12:57:12 goose: up to current file version: 27722026/09/21 12:57:12 OK 2_object_stats_trigger.sql (468.33µs)7732026/09/21 12:57:12 goose: up to current file version: 27742026/09/21 12:57:12 OK 2_object_stats_trigger.sql (459.04µs)7752026/09/21 12:57:12 goose: up to current file version: 27762026/09/21 12:57:12 OK 2_object_stats_trigger.sql (449.38µs)7772026/09/21 12:57:12 goose: up to current file version: 27782026/09/21 12:57:12 OK 20260920000000_drop_claims.sql (7.6ms)7792026/09/21 12:57:12 goose: successfully migrated database to version: 202609200000007802026/09/21 12:57:12 OK 20260920000000_drop_claims.sql (8.46ms)7812026/09/21 12:57:12 goose: successfully migrated database to version: 202609200000007822026/09/21 12:57:12 OK 1_commit_pending_closure.sql (1.6ms)7832026/09/21 12:57:12 OK 1_commit_pending_closure.sql (1.9ms)7842026/09/21 12:57:12 OK 2_object_stats_trigger.sql (655.63µs)7852026/09/21 12:57:12 goose: up to current file version: 27862026/09/21 12:57:12 OK 2_object_stats_trigger.sql (639.5µs)7872026/09/21 12:57:12 goose: up to current file version: 27882026/09/21 12:57:12 INFO Received uploads request method=POST path=/api/pending_closures789--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.49s)790=== CONT TestObjectStatsTrigger7912026-09-21 12:57:12.409 UTC [17318] ERROR: relation "goose_db_version" does not exist at character 367922026-09-21 12:57:12.409 UTC [17318] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7932026/09/21 12:57:12 INFO Received complete multipart upload request method=POST path=/api/multipart/complete7942026/09/21 12:57:12 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.60s)796=== CONT TestMultipartCleanup7972026/09/21 12:57:12 OK 20241026095416_initial_model.sql (67.61ms)7982026/09/21 12:57:12 OK 20251210153512_drop_unused_gin_index.sql (11.21ms)7992026/09/21 12:57:12 OK 20251218171726_add_pins.sql (13.2ms)8002026/09/21 12:57:12 OK 20260628120000_add_object_size_and_stats.sql (17.5ms)8012026/09/21 12:57:12 OK 20260905000000_add_claims.sql (19.39ms)8022026/09/21 12:57:12 OK 20260920000000_drop_claims.sql (7.84ms)8032026/09/21 12:57:12 goose: successfully migrated database to version: 202609200000008042026/09/21 12:57:12 OK 1_commit_pending_closure.sql (2.12ms)8052026/09/21 12:57:12 OK 2_object_stats_trigger.sql (493.13µs)8062026/09/21 12:57:12 goose: up to current file version: 2807--- PASS: TestReadRedirectUsesPublicS3URL (0.81s)808=== CONT TestServerTLSConfig809=== RUN TestServerTLSConfig/no_client_CA810=== PAUSE TestServerTLSConfig/no_client_CA811=== RUN TestServerTLSConfig/missing_CA_file812=== PAUSE TestServerTLSConfig/missing_CA_file813=== RUN TestServerTLSConfig/not_a_PEM_file814=== PAUSE TestServerTLSConfig/not_a_PEM_file815=== CONT TestService_NativeMTLS8162026/09/21 12:57:12 INFO Received uploads request method=POST path=/api/pending_closures8172026-09-21 12:57:12.830 UTC [17364] ERROR: relation "goose_db_version" does not exist at character 368182026-09-21 12:57:12.830 UTC [17364] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8192026-09-21 12:57:12.853 UTC [17365] ERROR: relation "goose_db_version" does not exist at character 368202026-09-21 12:57:12.853 UTC [17365] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8212026/09/21 12:57:12 OK 20241026095416_initial_model.sql (90.01ms)8222026/09/21 12:57:12 OK 20251210153512_drop_unused_gin_index.sql (6.41ms)8232026/09/21 12:57:12 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"824--- PASS: TestService_AuthMiddleware (1.10s)825=== CONT TestResurrectedObjectNotDeleted8262026/09/21 12:57:12 OK 20241026095416_initial_model.sql (69.98ms)8272026/09/21 12:57:12 OK 20251218171726_add_pins.sql (16.41ms)8282026/09/21 12:57:12 OK 20251210153512_drop_unused_gin_index.sql (8.09ms)8292026/09/21 12:57:12 OK 20260628120000_add_object_size_and_stats.sql (20.88ms)8302026/09/21 12:57:12 OK 20251218171726_add_pins.sql (18.94ms)8312026/09/21 12:57:13 OK 20260628120000_add_object_size_and_stats.sql (14.02ms)8322026/09/21 12:57:13 OK 20260905000000_add_claims.sql (21.71ms)8332026/09/21 12:57:13 OK 20260905000000_add_claims.sql (9.38ms)8342026/09/21 12:57:13 OK 20260920000000_drop_claims.sql (14.5ms)8352026/09/21 12:57:13 goose: successfully migrated database to version: 202609200000008362026/09/21 12:57:13 OK 1_commit_pending_closure.sql (2.39ms)8372026/09/21 12:57:13 OK 2_object_stats_trigger.sql (795.58µs)8382026/09/21 12:57:13 goose: up to current file version: 28392026/09/21 12:57:13 OK 20260920000000_drop_claims.sql (16.26ms)8402026/09/21 12:57:13 goose: successfully migrated database to version: 202609200000008412026/09/21 12:57:13 OK 1_commit_pending_closure.sql (1.96ms)8422026/09/21 12:57:13 OK 2_object_stats_trigger.sql (686.75µs)8432026/09/21 12:57:13 goose: up to current file version: 28442026/09/21 12:57:13 INFO Received cleanup request method=DELETE path=/api/pending_closures8452026/09/21 12:57:13 INFO Aborted multipart uploads count=08462026/09/21 12:57:13 INFO Received uploads request method=POST path=/api/pending_closures8472026/09/21 12:57:13 INFO Received cleanup request method=DELETE path=/api/pending_closures8482026-09-21 12:57:13.187 UTC [17371] ERROR: relation "goose_db_version" does not exist at character 368492026-09-21 12:57:13.187 UTC [17371] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8502026/09/21 12:57:13 INFO Aborted multipart uploads count=18512026/09/21 12:57:13 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete8522026-09-21 12:57:13.191 UTC [17233] ERROR: Closure does not exist: id=18532026-09-21 12:57:13.191 UTC [17233] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 16 at RAISE8542026-09-21 12:57:13.191 UTC [17233] STATEMENT: -- name: CommitPendingClosure :exec855 SELECT commit_pending_closure($1::bigint)856 857--- PASS: TestService_cleanupPendingClosuresHandler (1.34s)858=== CONT TestReadRedirectKeepsNarinfoProxied8592026/09/21 12:57:13 OK 20241026095416_initial_model.sql (57.33ms)8602026/09/21 12:57:13 OK 20251210153512_drop_unused_gin_index.sql (9.59ms)8612026/09/21 12:57:13 OK 20251218171726_add_pins.sql (17.14ms)8622026/09/21 12:57:13 OK 20260628120000_add_object_size_and_stats.sql (11.3ms)8632026/09/21 12:57:13 OK 20260905000000_add_claims.sql (17.97ms)8642026/09/21 12:57:13 OK 20260920000000_drop_claims.sql (5.78ms)8652026/09/21 12:57:13 goose: successfully migrated database to version: 202609200000008662026/09/21 12:57:13 OK 1_commit_pending_closure.sql (2.46ms)8672026/09/21 12:57:13 OK 2_object_stats_trigger.sql (691.88µs)8682026/09/21 12:57:13 goose: up to current file version: 28692026-09-21 12:57:13.461 UTC [17376] ERROR: relation "goose_db_version" does not exist at character 368702026-09-21 12:57:13.461 UTC [17376] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8712026/09/21 12:57:13 INFO Received uploads request method=POST path=/api/pending_closures8722026/09/21 12:57:13 INFO Received uploads request method=POST path=/api/pending_closures8732026/09/21 12:57:13 INFO Received uploads request method=POST path=/api/pending_closures8742026/09/21 12:57:13 OK 20241026095416_initial_model.sql (126.14ms)8752026/09/21 12:57:13 OK 20251210153512_drop_unused_gin_index.sql (8.08ms)8762026/09/21 12:57:13 OK 20251218171726_add_pins.sql (16.71ms)8772026/09/21 12:57:13 OK 20260628120000_add_object_size_and_stats.sql (26.86ms)8782026/09/21 12:57:13 INFO Received complete multipart upload request method=POST path=/api/multipart/complete879--- PASS: TestReadProxyRangeRequest (1.84s)880=== CONT TestReadRedirectNar8812026/09/21 12:57:13 OK 20260905000000_add_claims.sql (53.98ms)8822026/09/21 12:57:13 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=ZWEyYmY0Y2QtZDQzYi00MzRkLTlkMzEtNzBkMjgwZTU2YzEzLjhjZDYwYmIzLTc1OTQtNGZhNS1iZTJmLTc5MTlhYmRlOGY2YXgxNzg5OTk1NDMyNzk3OTE4MDAw parts=108832026/09/21 12:57:13 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete8842026/09/21 12:57:13 OK 20260920000000_drop_claims.sql (12.62ms)8852026/09/21 12:57:13 goose: successfully migrated database to version: 202609200000008862026/09/21 12:57:13 INFO Completed upload id=18872026/09/21 12:57:13 OK 1_commit_pending_closure.sql (2.15ms)8882026/09/21 12:57:13 INFO Received uploads request method=POST path=/api/pending_closures8892026/09/21 12:57:13 INFO Received uploads request method=POST path=/api/pending_closures8902026/09/21 12:57:13 OK 2_object_stats_trigger.sql (694.83µs)8912026/09/21 12:57:13 goose: up to current file version: 28922026/09/21 12:57:13 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo8932026/09/21 12:57:13 WARN Found objects in DB but missing from S3, will re-upload count=1894--- PASS: TestService_verifyS3Integrity (1.89s)895=== CONT TestMetricsInventory8962026-09-21 12:57:13.892 UTC [17428] ERROR: relation "goose_db_version" does not exist at character 368972026-09-21 12:57:13.892 UTC [17428] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8982026/09/21 12:57:14 OK 20241026095416_initial_model.sql (104.84ms)8992026/09/21 12:57:14 OK 20251210153512_drop_unused_gin_index.sql (8.99ms)9002026/09/21 12:57:14 OK 20251218171726_add_pins.sql (5.56ms)9012026/09/21 12:57:14 OK 20260628120000_add_object_size_and_stats.sql (21.96ms)9022026/09/21 12:57:14 OK 20260905000000_add_claims.sql (45.32ms)903--- PASS: TestObjectStatsTrigger (1.77s)904=== CONT TestReadProxyNarStreaming9052026/09/21 12:57:14 OK 20260920000000_drop_claims.sql (8.15ms)9062026/09/21 12:57:14 goose: successfully migrated database to version: 202609200000009072026/09/21 12:57:14 OK 1_commit_pending_closure.sql (2.12ms)9082026/09/21 12:57:14 OK 2_object_stats_trigger.sql (657.33µs)9092026/09/21 12:57:14 goose: up to current file version: 29102026/09/21 12:57:14 INFO Received uploads request method=POST path=/api/pending_closures9112026/09/21 12:57:14 INFO Received cleanup request method=DELETE path=/api/pending_closures9122026/09/21 12:57:14 INFO Aborted multipart uploads count=1913--- PASS: TestMultipartCleanup (1.99s)914=== CONT TestNARDeduplicationMetadataUploadBug915=== NAME TestOrphanedObjectsGC916 orphaned_objects_gc_test.go:290: GC Test Summary:917 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A918 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B919 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)920 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)921 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects922--- PASS: TestOrphanedObjectsGC (2.51s)923=== CONT TestReadProxyNarinfoAlreadyDecompressed9242026/09/21 12:57:14 WARN mTLS auth: subject not in bound subjects subject="CN=reader"9252026/09/21 12:57:14 WARN mTLS auth: subject not in bound subjects subject="CN=reader"926--- PASS: TestService_NativeMTLS (1.82s)927=== CONT TestCreatePendingClosureRejectsOversizedNAR9282026/09/21 12:57:14 INFO Received uploads request method=POST path=/api/pending_closures929--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)930=== CONT TestReadProxyNarinfo9312026/09/21 12:57:14 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9322026/09/21 12:57:14 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=ZWEyYmY0Y2QtZDQzYi00MzRkLTlkMzEtNzBkMjgwZTU2YzEzLjVmZTRmMzk0LTY0YjctNDJjOS1hZDM0LTRjNjc1ODNmYjU1YngxNzg5OTk1NDMzNTAxMzExMDAw parts=109332026/09/21 12:57:14 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete9342026/09/21 12:57:14 INFO Completed upload id=19352026/09/21 12:57:14 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000009362026/09/21 12:57:14 INFO Received uploads request method=POST path=/api/pending_closures9372026/09/21 12:57:14 INFO Starting cleanup of old closures method=DELETE path=/api/closures9382026/09/21 12:57:14 INFO Aborted multipart uploads count=09392026/09/21 12:57: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=09402026/09/21 12:57:14 INFO Vacuumed table table=pending_closures9412026/09/21 12:57:14 INFO Vacuumed table table=pending_objects9422026/09/21 12:57:14 INFO Vacuumed table table=multipart_uploads9432026/09/21 12:57:14 INFO Vacuumed table table=closures9442026/09/21 12:57:14 INFO Vacuumed table table=objects9452026/09/21 12:57:14 INFO Received get closure request method=GET path=/api/closures/00000000000000000000000000000000946--- PASS: TestService_createPendingClosureHandler (2.80s)947=== CONT TestIsValidCachePath948=== RUN TestIsValidCachePath/narinfo949=== PAUSE TestIsValidCachePath/narinfo950=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars951=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars952=== RUN TestIsValidCachePath/nar_zst953=== PAUSE TestIsValidCachePath/nar_zst954=== RUN TestIsValidCachePath/nar_xz955=== PAUSE TestIsValidCachePath/nar_xz956=== RUN TestIsValidCachePath/nar_bz2957=== PAUSE TestIsValidCachePath/nar_bz2958=== RUN TestIsValidCachePath/nar_uncompressed959=== PAUSE TestIsValidCachePath/nar_uncompressed960=== RUN TestIsValidCachePath/ls961=== PAUSE TestIsValidCachePath/ls962=== RUN TestIsValidCachePath/log963=== PAUSE TestIsValidCachePath/log964=== RUN TestIsValidCachePath/realisation965=== PAUSE TestIsValidCachePath/realisation966=== RUN TestIsValidCachePath/nix-cache-info967=== PAUSE TestIsValidCachePath/nix-cache-info968=== RUN TestIsValidCachePath/index.html969=== PAUSE TestIsValidCachePath/index.html970=== RUN TestIsValidCachePath/traversal_parent971=== PAUSE TestIsValidCachePath/traversal_parent972=== RUN TestIsValidCachePath/traversal_in_middle973=== PAUSE TestIsValidCachePath/traversal_in_middle974=== RUN TestIsValidCachePath/invalid_char_e975=== PAUSE TestIsValidCachePath/invalid_char_e976=== RUN TestIsValidCachePath/invalid_char_u977=== PAUSE TestIsValidCachePath/invalid_char_u978=== RUN TestIsValidCachePath/random_path979=== PAUSE TestIsValidCachePath/random_path980=== RUN TestIsValidCachePath/empty981=== PAUSE TestIsValidCachePath/empty982=== RUN TestIsValidCachePath/leading_slash983=== PAUSE TestIsValidCachePath/leading_slash984=== RUN TestIsValidCachePath/wrong_extension985=== PAUSE TestIsValidCachePath/wrong_extension986=== RUN TestIsValidCachePath/short_hash987=== PAUSE TestIsValidCachePath/short_hash988=== CONT TestParseSingleRange989=== RUN TestParseSingleRange/none990=== PAUSE TestParseSingleRange/none991=== RUN TestParseSingleRange/unknown_unit992=== PAUSE TestParseSingleRange/unknown_unit993=== RUN TestParseSingleRange/multi-range_ignored994=== PAUSE TestParseSingleRange/multi-range_ignored995=== RUN TestParseSingleRange/malformed_no_dash996=== PAUSE TestParseSingleRange/malformed_no_dash997=== RUN TestParseSingleRange/malformed_both_empty998=== PAUSE TestParseSingleRange/malformed_both_empty999=== RUN TestParseSingleRange/malformed_end_before_start1000=== PAUSE TestParseSingleRange/malformed_end_before_start1001=== RUN TestParseSingleRange/closed1002=== PAUSE TestParseSingleRange/closed1003=== RUN TestParseSingleRange/open-ended1004=== PAUSE TestParseSingleRange/open-ended1005=== RUN TestParseSingleRange/end_clamped_to_size1006=== PAUSE TestParseSingleRange/end_clamped_to_size1007=== RUN TestParseSingleRange/suffix1008=== PAUSE TestParseSingleRange/suffix1009=== RUN TestParseSingleRange/suffix_exceeds_size1010=== PAUSE TestParseSingleRange/suffix_exceeds_size1011=== RUN TestParseSingleRange/single_byte1012=== PAUSE TestParseSingleRange/single_byte1013=== RUN TestParseSingleRange/start_past_EOF1014=== PAUSE TestParseSingleRange/start_past_EOF1015=== RUN TestParseSingleRange/start_far_past_EOF1016=== PAUSE TestParseSingleRange/start_far_past_EOF1017=== CONT TestCacheConfigHandlerMaxNarSize1018--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)1019=== CONT TestGenerateLandingPage1020--- PASS: TestGenerateLandingPage (0.00s)1021=== CONT TestPinProtectsFromGC10222026-09-21 12:57:14.684 UTC [17588] ERROR: relation "goose_db_version" does not exist at character 3610232026-09-21 12:57:14.684 UTC [17588] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10242026-09-21 12:57:14.728 UTC [17597] ERROR: relation "goose_db_version" does not exist at character 3610252026-09-21 12:57:14.728 UTC [17597] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10262026/09/21 12:57:14 OK 20241026095416_initial_model.sql (35.72ms)10272026/09/21 12:57:14 OK 20251210153512_drop_unused_gin_index.sql (1.13ms)10282026/09/21 12:57:14 OK 20251218171726_add_pins.sql (3.53ms)10292026/09/21 12:57:14 OK 20241026095416_initial_model.sql (12.79ms)10302026/09/21 12:57:14 OK 20251210153512_drop_unused_gin_index.sql (8.11ms)1031--- PASS: TestResurrectedObjectNotDeleted (1.82s)1032=== CONT TestService_readinessHandler10332026/09/21 12:57:14 OK 20251218171726_add_pins.sql (17.06ms)10342026/09/21 12:57:14 OK 20260628120000_add_object_size_and_stats.sql (25.45ms)10352026/09/21 12:57:14 OK 20260905000000_add_claims.sql (7.65ms)10362026/09/21 12:57:14 OK 20260628120000_add_object_size_and_stats.sql (7.75ms)10372026/09/21 12:57:14 OK 20260920000000_drop_claims.sql (8.07ms)10382026/09/21 12:57:14 goose: successfully migrated database to version: 2026092000000010392026/09/21 12:57:14 OK 1_commit_pending_closure.sql (2.07ms)10402026/09/21 12:57:14 OK 2_object_stats_trigger.sql (633.75µs)10412026/09/21 12:57:14 goose: up to current file version: 210422026/09/21 12:57:14 OK 20260905000000_add_claims.sql (35.09ms)10432026/09/21 12:57:14 OK 20260920000000_drop_claims.sql (8.64ms)10442026/09/21 12:57:14 goose: successfully migrated database to version: 2026092000000010452026/09/21 12:57:14 OK 1_commit_pending_closure.sql (2.4ms)10462026/09/21 12:57:14 OK 2_object_stats_trigger.sql (447.08µs)10472026/09/21 12:57:14 goose: up to current file version: 21048--- PASS: TestReadRedirectKeepsNarinfoProxied (1.69s)1049=== CONT TestService_healthCheckHandler10502026-09-21 12:57:15.034 UTC [17657] ERROR: relation "goose_db_version" does not exist at character 3610512026-09-21 12:57:15.034 UTC [17657] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1052--- PASS: TestMetricsInventory (1.32s)1053=== CONT TestCacheStatsHandler10542026/09/21 12:57:15 OK 20241026095416_initial_model.sql (60.67ms)10552026/09/21 12:57:15 OK 20251210153512_drop_unused_gin_index.sql (7.66ms)10562026/09/21 12:57:15 OK 20251218171726_add_pins.sql (13.43ms)10572026/09/21 12:57:15 OK 20260628120000_add_object_size_and_stats.sql (10.64ms)10582026/09/21 12:57:15 OK 20260905000000_add_claims.sql (41.08ms)10592026/09/21 12:57:15 OK 20260920000000_drop_claims.sql (22.76ms)10602026/09/21 12:57:15 goose: successfully migrated database to version: 2026092000000010612026/09/21 12:57:15 OK 1_commit_pending_closure.sql (2.16ms)10622026/09/21 12:57:15 OK 2_object_stats_trigger.sql (727.29µs)10632026/09/21 12:57:15 goose: up to current file version: 21064--- PASS: TestReadRedirectNar (1.52s)1065=== CONT TestGCTaskStore_Fail1066--- PASS: TestGCTaskStore_Fail (0.00s)1067=== CONT TestClientSharedPathCommittedMidPush10682026-09-21 12:57:15.278 UTC [17663] ERROR: relation "goose_db_version" does not exist at character 3610692026-09-21 12:57:15.278 UTC [17663] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10702026-09-21 12:57:15.310 UTC [17666] ERROR: relation "goose_db_version" does not exist at character 3610712026-09-21 12:57:15.310 UTC [17666] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10722026-09-21 12:57:15.339 UTC [17667] ERROR: relation "goose_db_version" does not exist at character 3610732026-09-21 12:57:15.339 UTC [17667] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10742026/09/21 12:57:15 OK 20241026095416_initial_model.sql (54.13ms)10752026/09/21 12:57:15 OK 20251210153512_drop_unused_gin_index.sql (2.83ms)10762026/09/21 12:57:15 OK 20251218171726_add_pins.sql (7.43ms)10772026/09/21 12:57:15 OK 20260628120000_add_object_size_and_stats.sql (28.05ms)10782026/09/21 12:57:15 OK 20241026095416_initial_model.sql (77.37ms)10792026/09/21 12:57:15 OK 20251210153512_drop_unused_gin_index.sql (9.02ms)10802026/09/21 12:57:15 OK 20260905000000_add_claims.sql (35.3ms)10812026/09/21 12:57:15 OK 20251218171726_add_pins.sql (13.06ms)10822026/09/21 12:57:15 OK 20260920000000_drop_claims.sql (3.24ms)10832026/09/21 12:57:15 goose: successfully migrated database to version: 2026092000000010842026/09/21 12:57:15 OK 20241026095416_initial_model.sql (67.43ms)10852026/09/21 12:57:15 OK 20260628120000_add_object_size_and_stats.sql (3.72ms)10862026/09/21 12:57:15 OK 20251210153512_drop_unused_gin_index.sql (960.17µs)10872026/09/21 12:57:15 OK 1_commit_pending_closure.sql (3.13ms)10882026/09/21 12:57:15 OK 2_object_stats_trigger.sql (985.88µs)10892026/09/21 12:57:15 goose: up to current file version: 210902026/09/21 12:57:15 OK 20251218171726_add_pins.sql (2.78ms)10912026/09/21 12:57:15 OK 20260905000000_add_claims.sql (4.3ms)1092--- PASS: TestReadProxyNarStreaming (1.33s)1093=== CONT TestClientWithDependencies10942026/09/21 12:57:15 OK 20260920000000_drop_claims.sql (2.89ms)10952026/09/21 12:57:15 goose: successfully migrated database to version: 2026092000000010962026/09/21 12:57:15 OK 1_commit_pending_closure.sql (2.19ms)10972026/09/21 12:57:15 OK 2_object_stats_trigger.sql (889.58µs)10982026/09/21 12:57:15 goose: up to current file version: 210992026/09/21 12:57:15 OK 20260628120000_add_object_size_and_stats.sql (14.95ms)11002026-09-21 12:57:15.458 UTC [17668] ERROR: relation "goose_db_version" does not exist at character 3611012026-09-21 12:57:15.458 UTC [17668] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11022026/09/21 12:57:15 OK 20260905000000_add_claims.sql (22.63ms)11032026/09/21 12:57:15 OK 20260920000000_drop_claims.sql (1.28ms)11042026/09/21 12:57:15 goose: successfully migrated database to version: 2026092000000011052026/09/21 12:57:15 OK 1_commit_pending_closure.sql (2.18ms)11062026/09/21 12:57:15 OK 2_object_stats_trigger.sql (756.58µs)11072026/09/21 12:57:15 goose: up to current file version: 211082026/09/21 12:57:15 OK 20241026095416_initial_model.sql (61.44ms)11092026/09/21 12:57:15 OK 20251210153512_drop_unused_gin_index.sql (7.96ms)11102026/09/21 12:57:15 OK 20251218171726_add_pins.sql (24.78ms)11112026/09/21 12:57:15 OK 20260628120000_add_object_size_and_stats.sql (9.43ms)11122026/09/21 12:57:15 OK 20260905000000_add_claims.sql (41.66ms)11132026/09/21 12:57:15 OK 20260920000000_drop_claims.sql (25.93ms)11142026/09/21 12:57:15 goose: successfully migrated database to version: 2026092000000011152026/09/21 12:57:15 OK 1_commit_pending_closure.sql (2.33ms)11162026/09/21 12:57:15 OK 2_object_stats_trigger.sql (664µs)11172026/09/21 12:57:15 goose: up to current file version: 211182026-09-21 12:57:15.666 UTC [17677] ERROR: relation "goose_db_version" does not exist at character 3611192026-09-21 12:57:15.666 UTC [17677] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11202026-09-21 12:57:15.731 UTC [17679] ERROR: relation "goose_db_version" does not exist at character 3611212026-09-21 12:57:15.731 UTC [17679] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11222026/09/21 12:57:15 OK 20241026095416_initial_model.sql (104.26ms)11232026/09/21 12:57:15 OK 20251210153512_drop_unused_gin_index.sql (2.01ms)1124=== NAME TestNARDeduplicationMetadataUploadBug1125 metadata_upload_test.go:48: First store path: /nix/var/nix/builds/nix-14861-3745989896/TestNARDeduplicationMetadataUploadBug243302507/001/store/x9bljlaxncprmxzprsddybcqzsmc7mi1-file1.txt11262026/09/21 12:57:15 OK 20251218171726_add_pins.sql (24.15ms)11272026/09/21 12:57:15 OK 20260628120000_add_object_size_and_stats.sql (26.8ms)11282026/09/21 12:57:15 OK 20260905000000_add_claims.sql (15.26ms)11292026/09/21 12:57:15 OK 20260920000000_drop_claims.sql (1.54ms)11302026/09/21 12:57:15 goose: successfully migrated database to version: 2026092000000011312026/09/21 12:57:15 OK 1_commit_pending_closure.sql (2.07ms)11322026/09/21 12:57:15 OK 2_object_stats_trigger.sql (737.75µs)11332026/09/21 12:57:15 goose: up to current file version: 21134--- PASS: TestReadProxyNarinfo (1.40s)1135=== CONT TestGCTaskStore_PhaseUpdates1136--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)1137=== CONT TestClientMultipleUploads11382026/09/21 12:57:15 OK 20241026095416_initial_model.sql (95.38ms)11392026/09/21 12:57:15 OK 20251210153512_drop_unused_gin_index.sql (6.51ms)11402026/09/21 12:57:15 OK 20251218171726_add_pins.sql (5.19ms)11412026-09-21 12:57:15.920 UTC [17771] ERROR: relation "goose_db_version" does not exist at character 3611422026-09-21 12:57:15.920 UTC [17771] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11432026/09/21 12:57:15 OK 20260628120000_add_object_size_and_stats.sql (24.4ms)11442026/09/21 12:57:15 OK 20260905000000_add_claims.sql (17.5ms)11452026/09/21 12:57:15 OK 20260920000000_drop_claims.sql (10.86ms)11462026/09/21 12:57:15 goose: successfully migrated database to version: 2026092000000011472026/09/21 12:57:15 OK 1_commit_pending_closure.sql (2.07ms)11482026/09/21 12:57:15 OK 2_object_stats_trigger.sql (378.83µs)11492026/09/21 12:57:15 goose: up to current file version: 211502026/09/21 12:57:16 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"11512026/09/21 12:57:16 OK 20241026095416_initial_model.sql (81.77ms)11522026/09/21 12:57:16 OK 20251210153512_drop_unused_gin_index.sql (1.59ms)11532026/09/21 12:57:16 OK 20251218171726_add_pins.sql (14.71ms)11542026/09/21 12:57:16 OK 20260628120000_add_object_size_and_stats.sql (14.13ms)1155--- PASS: TestReadProxyNarinfoAlreadyDecompressed (1.60s)1156=== CONT TestGCTaskStore_CompletedAllowsNewTask1157--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)1158=== CONT TestClientIntegration11592026/09/21 12:57:16 OK 20260905000000_add_claims.sql (16.04ms)11602026-09-21 12:57:16.070 UTC [17816] ERROR: relation "goose_db_version" does not exist at character 3611612026-09-21 12:57:16.070 UTC [17816] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11622026/09/21 12:57:16 OK 20260920000000_drop_claims.sql (15.19ms)11632026/09/21 12:57:16 goose: successfully migrated database to version: 2026092000000011642026/09/21 12:57:16 OK 1_commit_pending_closure.sql (2.19ms)11652026/09/21 12:57:16 OK 2_object_stats_trigger.sql (708µs)11662026/09/21 12:57:16 goose: up to current file version: 211672026/09/21 12:57:16 INFO Received uploads request method=POST path=/api/pending_closures11682026/09/21 12:57:16 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)11692026/09/21 12:57:16 INFO Uploading x9bljlaxncprmxzprsddybcqzsmc7mi1-file1.txt (160B)11702026/09/21 12:57:16 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"11712026/09/21 12:57:16 WARN Failed to register uploaded object key=x9bljlaxncprmxzprsddybcqzsmc7mi1.ls error="server returned 404: 404 page not found\n"11722026/09/21 12:57:16 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign11732026/09/21 12:57:16 INFO Signed narinfos id=1 count=111742026/09/21 12:57:16 INFO Uploading 1 narinfos11752026/09/21 12:57:16 OK 20241026095416_initial_model.sql (45.3ms)11762026/09/21 12:57:16 OK 20251210153512_drop_unused_gin_index.sql (6.45ms)11772026/09/21 12:57:16 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete11782026/09/21 12:57:16 WARN Failed to register uploaded object key=x9bljlaxncprmxzprsddybcqzsmc7mi1.narinfo error="server returned 404: 404 page not found\n"11792026/09/21 12:57:16 OK 20251218171726_add_pins.sql (10ms)11802026/09/21 12:57:16 INFO Completed upload id=111812026/09/21 12:57:16 INFO Upload complete. (284ms)1182=== NAME TestNARDeduplicationMetadataUploadBug1183 metadata_upload_test.go:54: Retrieved narinfo from S3:1184 StorePath: /nix/var/nix/builds/nix-14861-3745989896/TestNARDeduplicationMetadataUploadBug243302507/001/store/x9bljlaxncprmxzprsddybcqzsmc7mi1-file1.txt1185 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1186 Compression: zstd1187 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1188 NarSize: 1601189 References: 1190 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1191 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1192 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1193 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}11942026/09/21 12:57:16 OK 20260628120000_add_object_size_and_stats.sql (28.99ms)11952026/09/21 12:57:16 OK 20260905000000_add_claims.sql (22.26ms)11962026/09/21 12:57:16 OK 20260920000000_drop_claims.sql (18.73ms)11972026/09/21 12:57:16 goose: successfully migrated database to version: 2026092000000011982026/09/21 12:57:16 OK 1_commit_pending_closure.sql (2.22ms)11992026/09/21 12:57:16 OK 2_object_stats_trigger.sql (613.13µs)12002026/09/21 12:57:16 goose: up to current file version: 212012026-09-21 12:57:16.248 UTC [17825] ERROR: relation "goose_db_version" does not exist at character 3612022026-09-21 12:57:16.248 UTC [17825] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1203 metadata_upload_test.go:64: Second store path (same content): /nix/var/nix/builds/nix-14861-3745989896/TestNARDeduplicationMetadataUploadBug243302507/001/store/l1g3f90dpi5cp4vl7rhpr4491h3dz802-file2.txt12042026/09/21 12:57:16 OK 20241026095416_initial_model.sql (44.15ms)12052026/09/21 12:57:16 OK 20251210153512_drop_unused_gin_index.sql (5.43ms)12062026/09/21 12:57:16 OK 20251218171726_add_pins.sql (16.57ms)12072026/09/21 12:57:16 OK 20260628120000_add_object_size_and_stats.sql (26.11ms)12082026/09/21 12:57:16 WARN readiness check failed error="closed pool"1209--- PASS: TestService_readinessHandler (1.61s)1210=== CONT TestGCTaskStore_GetReturnsLatest1211--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)1212=== CONT TestClientErrorHandling1213=== RUN TestClientErrorHandling/InvalidStorePath1214=== PAUSE TestClientErrorHandling/InvalidStorePath1215=== RUN TestClientErrorHandling/InvalidAuthToken1216=== PAUSE TestClientErrorHandling/InvalidAuthToken1217=== RUN TestClientErrorHandling/ServerNotAvailable1218=== PAUSE TestClientErrorHandling/ServerNotAvailable1219=== CONT TestReadProxyHead12202026/09/21 12:57:16 OK 20260905000000_add_claims.sql (26.96ms)12212026/09/21 12:57:16 OK 20260920000000_drop_claims.sql (12.49ms)12222026/09/21 12:57:16 goose: successfully migrated database to version: 2026092000000012232026/09/21 12:57:16 OK 1_commit_pending_closure.sql (2.24ms)12242026/09/21 12:57:16 OK 2_object_stats_trigger.sql (702.42µs)12252026/09/21 12:57:16 goose: up to current file version: 212262026-09-21 12:57:16.465 UTC [17838] ERROR: relation "goose_db_version" does not exist at character 3612272026-09-21 12:57:16.465 UTC [17838] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12282026/09/21 12:57:16 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"1229=== NAME TestPinProtectsFromGC1230 client_integration_test.go:731: Pinned store path: /nix/var/nix/builds/nix-14861-3745989896/TestPinProtectsFromGC1483842770/001/store/nv8i5k3m2j3g8vw6l7fwx9grginq4rv0-pinned-file.txt1231 client_integration_test.go:732: Unpinned store path: /nix/var/nix/builds/nix-14861-3745989896/TestPinProtectsFromGC1483842770/001/store/w2mibscdg4jh6d28h5djdq2wl3qm94yz-unpinned-file.txt1232--- PASS: TestService_healthCheckHandler (1.67s)1233=== CONT TestGCTaskStore_GetEmpty1234--- PASS: TestGCTaskStore_GetEmpty (0.00s)1235=== CONT TestReadProxyDisabled12362026/09/21 12:57:16 INFO Received uploads request method=POST path=/api/pending_closures12372026/09/21 12:57:16 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)12382026/09/21 12:57:16 OK 20241026095416_initial_model.sql (68.46ms)12392026/09/21 12:57:16 OK 20251210153512_drop_unused_gin_index.sql (11.62ms)12402026/09/21 12:57:16 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign12412026/09/21 12:57:16 INFO Signed narinfos id=2 count=112422026/09/21 12:57:16 WARN Failed to register uploaded object key=l1g3f90dpi5cp4vl7rhpr4491h3dz802.ls error="server returned 404: 404 page not found\n"12432026/09/21 12:57:16 INFO Uploading 1 narinfos12442026/09/21 12:57:16 OK 20251218171726_add_pins.sql (6.81ms)12452026/09/21 12:57:16 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete12462026/09/21 12:57:16 WARN Failed to register uploaded object key=l1g3f90dpi5cp4vl7rhpr4491h3dz802.narinfo error="server returned 404: 404 page not found\n"12472026/09/21 12:57:16 INFO Completed upload id=212482026/09/21 12:57:16 INFO Upload complete. (245ms)1249=== NAME TestNARDeduplicationMetadataUploadBug1250 metadata_upload_test.go:76: Retrieved narinfo from S3:1251 StorePath: /nix/var/nix/builds/nix-14861-3745989896/TestNARDeduplicationMetadataUploadBug243302507/001/store/l1g3f90dpi5cp4vl7rhpr4491h3dz802-file2.txt1252 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1253 Compression: zstd1254 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1255 NarSize: 1601256 References: 1257 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1258 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1259 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1260 {"version":1,"root":{"type":"regular","size":44}}12612026/09/21 12:57:16 OK 20260628120000_add_object_size_and_stats.sql (16.06ms)12622026/09/21 12:57:16 OK 20260905000000_add_claims.sql (16.06ms)1263--- PASS: TestNARDeduplicationMetadataUploadBug (2.18s)1264=== CONT TestClientCADerivations12652026-09-21 12:57:16.617 UTC [17847] ERROR: relation "goose_db_version" does not exist at character 3612662026-09-21 12:57:16.617 UTC [17847] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12672026/09/21 12:57:16 OK 20260920000000_drop_claims.sql (15.53ms)12682026/09/21 12:57:16 goose: successfully migrated database to version: 202609200000001269=== NAME TestOrphanedObjectsGCStressTest1270 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains12712026/09/21 12:57:16 OK 1_commit_pending_closure.sql (2.24ms)12722026/09/21 12:57:16 OK 2_object_stats_trigger.sql (597.25µs)12732026/09/21 12:57:16 goose: up to current file version: 21274 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion12752026/09/21 12:57:16 OK 20241026095416_initial_model.sql (57.32ms)12762026/09/21 12:57:16 OK 20251210153512_drop_unused_gin_index.sql (11.16ms)12772026/09/21 12:57:16 OK 20251218171726_add_pins.sql (13.93ms)12782026/09/21 12:57:16 OK 20260628120000_add_object_size_and_stats.sql (3.14ms)1279--- PASS: TestCacheStatsHandler (1.67s)1280=== CONT TestReadProxyRootRedirectsToIndexHTML12812026/09/21 12:57:16 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"12822026/09/21 12:57:16 OK 20260905000000_add_claims.sql (14.74ms)12832026/09/21 12:57:16 OK 20260920000000_drop_claims.sql (18.08ms)12842026/09/21 12:57:16 goose: successfully migrated database to version: 2026092000000012852026/09/21 12:57:16 OK 1_commit_pending_closure.sql (2.29ms)12862026/09/21 12:57:16 OK 2_object_stats_trigger.sql (793.83µs)12872026/09/21 12:57:16 goose: up to current file version: 212882026/09/21 12:57:16 INFO Received uploads request method=POST path=/api/pending_closures12892026/09/21 12:57:16 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)12902026/09/21 12:57:16 INFO Uploading nv8i5k3m2j3g8vw6l7fwx9grginq4rv0-pinned-file.txt (128B)12912026/09/21 12:57:16 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"12922026/09/21 12:57:16 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign12932026/09/21 12:57:16 INFO Signed narinfos id=1 count=112942026/09/21 12:57:16 INFO Uploading 1 narinfos12952026/09/21 12:57:16 WARN Failed to register uploaded object key=nv8i5k3m2j3g8vw6l7fwx9grginq4rv0.ls error="server returned 404: 404 page not found\n"12962026/09/21 12:57:16 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete12972026/09/21 12:57:16 WARN Failed to register uploaded object key=nv8i5k3m2j3g8vw6l7fwx9grginq4rv0.narinfo error="server returned 404: 404 page not found\n"12982026/09/21 12:57:16 INFO Completed upload id=112992026/09/21 12:57:16 INFO Upload complete. (289ms)13002026-09-21 12:57:16.918 UTC [17910] ERROR: relation "goose_db_version" does not exist at character 3613012026-09-21 12:57:16.918 UTC [17910] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13022026/09/21 12:57:17 OK 20241026095416_initial_model.sql (67.46ms)13032026/09/21 12:57:17 OK 20251210153512_drop_unused_gin_index.sql (7.81ms)13042026/09/21 12:57:17 OK 20251218171726_add_pins.sql (7.96ms)13052026/09/21 12:57:17 OK 20260628120000_add_object_size_and_stats.sql (13.55ms)13062026/09/21 12:57:17 OK 20260905000000_add_claims.sql (44.62ms)13072026/09/21 12:57:17 OK 20260920000000_drop_claims.sql (14.35ms)13082026/09/21 12:57:17 goose: successfully migrated database to version: 2026092000000013092026/09/21 12:57:17 OK 1_commit_pending_closure.sql (2.26ms)13102026/09/21 12:57:17 OK 2_object_stats_trigger.sql (915.88µs)13112026/09/21 12:57:17 goose: up to current file version: 213122026/09/21 12:57:17 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"13132026/09/21 12:57:17 INFO Received uploads request method=POST path=/api/pending_closures13142026/09/21 12:57:17 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)13152026/09/21 12:57:17 INFO Uploading w2mibscdg4jh6d28h5djdq2wl3qm94yz-unpinned-file.txt (128B)13162026/09/21 12:57:17 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"13172026/09/21 12:57:17 WARN Failed to register uploaded object key=w2mibscdg4jh6d28h5djdq2wl3qm94yz.ls error="server returned 404: 404 page not found\n"13182026/09/21 12:57:17 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign13192026/09/21 12:57:17 INFO Signed narinfos id=2 count=113202026/09/21 12:57:17 INFO Uploading 1 narinfos13212026-09-21 12:57:17.264 UTC [17925] ERROR: relation "goose_db_version" does not exist at character 3613222026-09-21 12:57:17.264 UTC [17925] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13232026/09/21 12:57:17 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete13242026/09/21 12:57:17 WARN Failed to register uploaded object key=w2mibscdg4jh6d28h5djdq2wl3qm94yz.narinfo error="server returned 404: 404 page not found\n"13252026/09/21 12:57:17 INFO Completed upload id=213262026/09/21 12:57:17 INFO Upload complete. (316ms)13272026-09-21 12:57:17.293 UTC [17927] ERROR: relation "goose_db_version" does not exist at character 3613282026-09-21 12:57:17.293 UTC [17927] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13292026/09/21 12:57:17 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"13302026/09/21 12:57:17 INFO Received create pin request method=POST path=/api/pins/myapp13312026/09/21 12:57:17 INFO Created/updated pin name=myapp store_path=/nix/var/nix/builds/nix-14861-3745989896/TestPinProtectsFromGC1483842770/001/store/nv8i5k3m2j3g8vw6l7fwx9grginq4rv0-pinned-file.txt narinfo_key=nv8i5k3m2j3g8vw6l7fwx9grginq4rv0.narinfo13322026/09/21 12:57:17 INFO Starting cleanup of old closures method=DELETE path=/api/closures13332026/09/21 12:57:17 INFO Garbage collection started13342026/09/21 12:57:17 INFO Aborted multipart uploads count=013352026/09/21 12:57:17 WARN Force mode enabled - objects will be deleted immediately without grace period13362026/09/21 12:57:17 OK 20241026095416_initial_model.sql (120.3ms)13372026/09/21 12:57:17 OK 20251210153512_drop_unused_gin_index.sql (7.7ms)13382026/09/21 12:57:17 INFO Received uploads request method=POST path=/api/pending_closures13392026/09/21 12:57:17 OK 20241026095416_initial_model.sql (118.8ms)13402026/09/21 12:57:17 OK 20251210153512_drop_unused_gin_index.sql (15.05ms)13412026/09/21 12:57:17 OK 20251218171726_add_pins.sql (30.83ms)13422026/09/21 12:57:17 OK 20260628120000_add_object_size_and_stats.sql (25.51ms)13432026/09/21 12:57:17 OK 20251218171726_add_pins.sql (32.33ms)13442026/09/21 12:57:17 OK 20260628120000_add_object_size_and_stats.sql (26.93ms)1345=== NAME TestClientMultipleUploads1346 client_integration_test.go:358: Created store path 0: /nix/var/nix/builds/nix-14861-3745989896/TestClientMultipleUploads2982629239/001/store/6pdxknm9y52h7grddl6qkddabg5nxqxn-test-file-0.txt13472026/09/21 12:57:17 OK 20260905000000_add_claims.sql (54.5ms)13482026/09/21 12:57:17 OK 20260920000000_drop_claims.sql (21.56ms)13492026/09/21 12:57:17 goose: successfully migrated database to version: 2026092000000013502026/09/21 12:57:17 OK 1_commit_pending_closure.sql (2.17ms)13512026/09/21 12:57:17 OK 2_object_stats_trigger.sql (703.54µs)13522026/09/21 12:57:17 goose: up to current file version: 213532026/09/21 12:57:17 OK 20260905000000_add_claims.sql (50.27ms)13542026/09/21 12:57:17 OK 20260920000000_drop_claims.sql (21.28ms)13552026/09/21 12:57:17 goose: successfully migrated database to version: 2026092000000013562026/09/21 12:57:17 OK 1_commit_pending_closure.sql (2.18ms)13572026/09/21 12:57:17 OK 2_object_stats_trigger.sql (645.83µs)13582026/09/21 12:57:17 goose: up to current file version: 213592026-09-21 12:57:17.658 UTC [17986] ERROR: relation "goose_db_version" does not exist at character 3613602026-09-21 12:57:17.658 UTC [17986] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1361 client_integration_test.go:358: Created store path 1: /nix/var/nix/builds/nix-14861-3745989896/TestClientMultipleUploads2982629239/001/store/pf9lxacg12pzhrawjpldh8kfsyxplwbk-test-file-1.txt13622026/09/21 12:57:17 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"1363=== NAME TestClientIntegration1364 client_integration_test.go:286: Created store path: /nix/var/nix/builds/nix-14861-3745989896/TestClientIntegration686740500/002/store/lr6qv4xjrs7hvrnsk6xycrp13m187fvi-test-file.txt13652026/09/21 12:57:17 OK 20241026095416_initial_model.sql (39.96ms)13662026/09/21 12:57:17 OK 20251210153512_drop_unused_gin_index.sql (573.5µs)13672026/09/21 12:57:17 OK 20251218171726_add_pins.sql (2.45ms)1368--- PASS: TestReadProxyHead (1.38s)1369=== CONT TestReadProxyInvalidPath13702026/09/21 12:57:17 OK 20260628120000_add_object_size_and_stats.sql (15.84ms)13712026/09/21 12:57:17 OK 20260905000000_add_claims.sql (26.66ms)13722026/09/21 12:57:17 OK 20260920000000_drop_claims.sql (20.05ms)13732026/09/21 12:57:17 goose: successfully migrated database to version: 2026092000000013742026/09/21 12:57:17 OK 1_commit_pending_closure.sql (2.03ms)13752026/09/21 12:57:17 OK 2_object_stats_trigger.sql (714µs)13762026/09/21 12:57:17 goose: up to current file version: 213772026/09/21 12:57:17 INFO Received uploads request method=POST path=/api/pending_closures13782026/09/21 12:57:17 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)13792026/09/21 12:57:17 INFO Uploading c3v4cvhbi6n5qnqgdpj9g6k77c0shcli-shared-dep (136B)13802026/09/21 12:57:17 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"1381=== NAME TestClientMultipleUploads1382 client_integration_test.go:358: Created store path 2: /nix/var/nix/builds/nix-14861-3745989896/TestClientMultipleUploads2982629239/001/store/1y331kks17a2gf1q2wph5n170jzfj4b5-test-file-2.txt13832026/09/21 12:57:17 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign13842026/09/21 12:57:17 WARN Failed to register uploaded object key=c3v4cvhbi6n5qnqgdpj9g6k77c0shcli.ls error="server returned 404: 404 page not found\n"13852026/09/21 12:57:17 INFO Signed narinfos id=2 count=113862026/09/21 12:57:17 INFO Uploading 1 narinfos13872026/09/21 12:57:17 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete13882026/09/21 12:57:17 WARN Failed to register uploaded object key=c3v4cvhbi6n5qnqgdpj9g6k77c0shcli.narinfo error="server returned 404: 404 page not found\n"13892026/09/21 12:57:17 INFO Completed upload id=213902026/09/21 12:57:17 INFO Upload complete. (341ms)13912026/09/21 12:57:17 INFO Received uploads request method=POST path=/api/pending_closures13922026/09/21 12:57:17 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)13932026/09/21 12:57:17 INFO Uploading 6ywpy1683h8hr0rkjipygm4hh90bhdia-top (256B)13942026/09/21 12:57:17 INFO Uploading c3v4cvhbi6n5qnqgdpj9g6k77c0shcli-shared-dep (136B)13952026/09/21 12:57:17 WARN Failed to register uploaded object key=nar/1i2jhj4p740j4rsbg9rlb9fg6xxy0cf2a0ax1m265h6z2w3978s8.nar.zst error="server returned 404: 404 page not found\n"13962026/09/21 12:57:17 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"1397--- PASS: TestReadProxyDisabled (1.39s)1398=== CONT TestReadProxy40413992026/09/21 12:57:17 WARN Failed to register uploaded object key=6ywpy1683h8hr0rkjipygm4hh90bhdia.ls error="server returned 404: 404 page not found\n"14002026/09/21 12:57:17 WARN Failed to register uploaded object key=c3v4cvhbi6n5qnqgdpj9g6k77c0shcli.ls error="server returned 404: 404 page not found\n"14012026/09/21 12:57:17 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign14022026/09/21 12:57:17 INFO Signed narinfos id=1 count=114032026/09/21 12:57:17 INFO Received sign narinfos request method=POST path=/api/pending_closures/3/sign14042026/09/21 12:57:17 INFO Signed narinfos id=3 count=114052026/09/21 12:57:17 INFO Uploading 2 narinfos14062026/09/21 12:57:17 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=014072026/09/21 12:57:17 WARN Failed to register uploaded object key=6ywpy1683h8hr0rkjipygm4hh90bhdia.narinfo error="server returned 404: 404 page not found\n"14082026/09/21 12:57:18 WARN Failed to register uploaded object key=c3v4cvhbi6n5qnqgdpj9g6k77c0shcli.narinfo error="server returned 404: 404 page not found\n"14092026/09/21 12:57:18 INFO Received complete upload request method=POST path=/api/pending_closures/3/complete14102026/09/21 12:57:18 INFO Completed upload id=314112026/09/21 12:57:18 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete14122026/09/21 12:57:18 INFO Completed upload id=114132026/09/21 12:57:18 INFO Upload complete. (784ms)14142026/09/21 12:57:18 INFO Vacuumed table table=pending_closures1415=== NAME TestClientSharedPathCommittedMidPush1416 client_integration_test.go:680: Retrieved narinfo from S3:1417 StorePath: /nix/var/nix/builds/nix-14861-3745989896/TestClientSharedPathCommittedMidPush1975739007/001/store/c3v4cvhbi6n5qnqgdpj9g6k77c0shcli-shared-dep1418 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1419 Compression: zstd1420 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821421 NarSize: 1361422 References: 1423 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n14242026/09/21 12:57:18 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"1425 client_integration_test.go:680: Retrieved narinfo from S3:1426 StorePath: /nix/var/nix/builds/nix-14861-3745989896/TestClientSharedPathCommittedMidPush1975739007/001/store/6ywpy1683h8hr0rkjipygm4hh90bhdia-top1427 URL: nar/1i2jhj4p740j4rsbg9rlb9fg6xxy0cf2a0ax1m265h6z2w3978s8.nar.zst1428 Compression: zstd1429 NarHash: sha256:1i2jhj4p740j4rsbg9rlb9fg6xxy0cf2a0ax1m265h6z2w3978s81430 NarSize: 2561431 References: /nix/var/nix/builds/nix-14861-3745989896/TestClientSharedPathCommittedMidPush1975739007/001/store/c3v4cvhbi6n5qnqgdpj9g6k77c0shcli-shared-dep1432 CA: text:sha256:13c9fh0fbjiy1hfic2wdm9pfflsq311fcy21y911gf216l0zwnpz14332026/09/21 12:57:18 INFO Vacuumed table table=pending_objects14342026/09/21 12:57:18 INFO Vacuumed table table=multipart_uploads14352026/09/21 12:57:18 INFO Vacuumed table table=closures1436--- PASS: TestClientSharedPathCommittedMidPush (2.84s)1437=== CONT TestGCMetrics14382026/09/21 12:57:18 INFO Vacuumed table table=objects14392026/09/21 12:57:18 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"14402026/09/21 12:57:18 INFO Received uploads request method=POST path=/api/pending_closures14412026/09/21 12:57:18 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)14422026/09/21 12:57:18 INFO Uploading lr6qv4xjrs7hvrnsk6xycrp13m187fvi-test-file.txt (152B)14432026/09/21 12:57:18 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"14442026/09/21 12:57:18 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign14452026/09/21 12:57:18 WARN Failed to register uploaded object key=lr6qv4xjrs7hvrnsk6xycrp13m187fvi.ls error="server returned 404: 404 page not found\n"14462026/09/21 12:57:18 INFO Signed narinfos id=1 count=114472026/09/21 12:57:18 INFO Uploading 1 narinfos14482026/09/21 12:57:18 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete14492026/09/21 12:57:18 WARN Failed to register uploaded object key=lr6qv4xjrs7hvrnsk6xycrp13m187fvi.narinfo error="server returned 404: 404 page not found\n"14502026/09/21 12:57:18 INFO Completed upload id=114512026/09/21 12:57:18 INFO Upload complete. (361ms)14522026/09/21 12:57:18 INFO Received uploads request method=POST path=/api/pending_closures1453--- PASS: TestReadProxyRootRedirectsToIndexHTML (1.59s)1454=== CONT TestReadProxyConditionalGet14552026/09/21 12:57:18 INFO Received uploads request method=POST path=/api/pending_closures14562026/09/21 12:57:18 INFO Received uploads request method=POST path=/api/pending_closures14572026/09/21 12:57:18 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)14582026/09/21 12:57:18 INFO Uploading 6pdxknm9y52h7grddl6qkddabg5nxqxn-test-file-0.txt (160B)14592026/09/21 12:57:18 INFO Uploading pf9lxacg12pzhrawjpldh8kfsyxplwbk-test-file-1.txt (160B)14602026/09/21 12:57:18 INFO Uploading 1y331kks17a2gf1q2wph5n170jzfj4b5-test-file-2.txt (160B)14612026/09/21 12:57:18 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"14622026/09/21 12:57:18 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"14632026/09/21 12:57:18 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"14642026/09/21 12:57:18 INFO All 1 paths already cached1465=== NAME TestClientWithDependencies1466 client_integration_test.go:613: Built derivation: /nix/var/nix/builds/nix-14861-3745989896/TestClientWithDependencies387885007/001/store/mpl2kyhbp78ir9fgfc4dl8xcpxwsb86n-test-script1467=== NAME TestClientIntegration1468 client_integration_test.go:312: Retrieved narinfo from S3:1469 StorePath: /nix/var/nix/builds/nix-14861-3745989896/TestClientIntegration686740500/002/store/lr6qv4xjrs7hvrnsk6xycrp13m187fvi-test-file.txt1470 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1471 Compression: zstd1472 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11473 NarSize: 1521474 References: 1475 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11476 client_integration_test.go:313: Retrieved .ls file from S3 (compressed size: 77 bytes)1477 client_integration_test.go:313: Decompressed .ls content (64 bytes):1478 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1479 client_integration_test.go:316: Testing garbage collection...14802026/09/21 12:57:18 WARN Failed to register uploaded object key=1y331kks17a2gf1q2wph5n170jzfj4b5.ls error="server returned 404: 404 page not found\n"14812026/09/21 12:57:18 WARN Failed to register uploaded object key=pf9lxacg12pzhrawjpldh8kfsyxplwbk.ls error="server returned 404: 404 page not found\n"14822026/09/21 12:57:18 INFO Received sign narinfos request method=POST path=/api/pending_closures/3/sign14832026/09/21 12:57:18 WARN Failed to register uploaded object key=6pdxknm9y52h7grddl6qkddabg5nxqxn.ls error="server returned 404: 404 page not found\n"14842026/09/21 12:57:18 INFO Signed narinfos id=3 count=114852026/09/21 12:57:18 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign14862026/09/21 12:57:18 INFO Signed narinfos id=1 count=114872026/09/21 12:57:18 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign14882026/09/21 12:57:18 INFO Signed narinfos id=2 count=114892026/09/21 12:57:18 INFO Uploading 3 narinfos14902026/09/21 12:57:18 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete14912026/09/21 12:57:18 WARN Failed to register uploaded object key=pf9lxacg12pzhrawjpldh8kfsyxplwbk.narinfo error="server returned 404: 404 page not found\n"14922026/09/21 12:57:18 WARN Failed to register uploaded object key=1y331kks17a2gf1q2wph5n170jzfj4b5.narinfo error="server returned 404: 404 page not found\n"14932026/09/21 12:57:18 WARN Failed to register uploaded object key=6pdxknm9y52h7grddl6qkddabg5nxqxn.narinfo error="server returned 404: 404 page not found\n"14942026/09/21 12:57:18 INFO Completed upload id=114952026/09/21 12:57:18 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete14962026/09/21 12:57:18 INFO Completed upload id=214972026/09/21 12:57:18 INFO Received complete upload request method=POST path=/api/pending_closures/3/complete14982026/09/21 12:57:18 INFO Completed upload id=314992026/09/21 12:57:18 INFO Upload complete. (401ms)1500=== NAME TestClientMultipleUploads1501 client_integration_test.go:369: Uploaded 3 paths in 499.732959ms15022026-09-21 12:57:18.404 UTC [18145] ERROR: relation "goose_db_version" does not exist at character 3615032026-09-21 12:57:18.404 UTC [18145] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1504--- PASS: TestClientMultipleUploads (2.56s)1505=== CONT TestGCTaskStore_ConflictDifferentParams1506--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)1507=== CONT TestGCBugBareHashReferences15082026/09/21 12:57:18 INFO Starting cleanup of old closures method=DELETE path=/api/closures15092026/09/21 12:57:18 INFO Garbage collection started15102026/09/21 12:57:18 INFO Aborted multipart uploads count=015112026/09/21 12:57:18 WARN Force mode enabled - objects will be deleted immediately without grace period15122026/09/21 12:57:18 OK 20241026095416_initial_model.sql (37.23ms)15132026/09/21 12:57:18 OK 20251210153512_drop_unused_gin_index.sql (1.06ms)1514=== NAME TestClientWithDependencies1515 client_integration_test.go:615: Found 1 dependencies (including self)15162026/09/21 12:57:18 OK 20251218171726_add_pins.sql (4.54ms)15172026/09/21 12:57:18 OK 20260628120000_add_object_size_and_stats.sql (4.21ms)15182026/09/21 12:57:18 OK 20260905000000_add_claims.sql (13.2ms)15192026/09/21 12:57:18 OK 20260920000000_drop_claims.sql (4.82ms)15202026/09/21 12:57:18 goose: successfully migrated database to version: 2026092000000015212026/09/21 12:57:18 OK 1_commit_pending_closure.sql (3.9ms)15222026/09/21 12:57:18 OK 2_object_stats_trigger.sql (700.54µs)15232026/09/21 12:57:18 goose: up to current file version: 21524=== NAME TestOrphanedObjectsGCStressTest1525 orphaned_objects_gc_test.go:509: Stress test completed successfully:1526 orphaned_objects_gc_test.go:510: - Active objects preserved: 201527 orphaned_objects_gc_test.go:511: - Objects deleted: 2101528 orphaned_objects_gc_test.go:512: - Total GC'd: 2101529--- PASS: TestOrphanedObjectsGCStressTest (6.70s)1530=== CONT TestGCTaskStore_DeduplicateSameParams1531--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)1532=== CONT TestLeadEndsOnShutdown15332026-09-21 12:57:18.692 UTC [18238] ERROR: relation "goose_db_version" does not exist at character 3615342026-09-21 12:57:18.692 UTC [18238] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15352026/09/21 12:57:18 OK 20241026095416_initial_model.sql (32.61ms)15362026/09/21 12:57:18 OK 20251210153512_drop_unused_gin_index.sql (11.21ms)1537--- PASS: TestReadProxyInvalidPath (1.03s)1538=== CONT TestGCTaskStore_StartNew1539--- PASS: TestGCTaskStore_StartNew (0.00s)1540=== CONT TestLeadElectsOneAndHandsOver15412026/09/21 12:57:18 OK 20251218171726_add_pins.sql (17.4ms)15422026-09-21 12:57:18.820 UTC [18250] ERROR: relation "goose_db_version" does not exist at character 3615432026-09-21 12:57:18.820 UTC [18250] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15442026/09/21 12:57:18 OK 20260628120000_add_object_size_and_stats.sql (19.98ms)15452026/09/21 12:57:18 OK 20260905000000_add_claims.sql (24.26ms)15462026/09/21 12:57:18 OK 20260920000000_drop_claims.sql (3.93ms)15472026/09/21 12:57:18 goose: successfully migrated database to version: 2026092000000015482026/09/21 12:57:18 OK 1_commit_pending_closure.sql (2.34ms)15492026/09/21 12:57:18 OK 2_object_stats_trigger.sql (538µs)15502026/09/21 12:57:18 goose: up to current file version: 215512026/09/21 12:57:18 OK 20241026095416_initial_model.sql (14.23ms)15522026/09/21 12:57:18 OK 20251210153512_drop_unused_gin_index.sql (6.76ms)15532026/09/21 12:57:18 OK 20251218171726_add_pins.sql (9.88ms)15542026/09/21 12:57:18 OK 20260628120000_add_object_size_and_stats.sql (11.57ms)15552026/09/21 12:57:18 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"15562026/09/21 12:57:18 INFO Received uploads request method=POST path=/api/pending_closures15572026/09/21 12:57:18 OK 20260905000000_add_claims.sql (57ms)15582026/09/21 12:57:18 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15592026/09/21 12:57:18 INFO Uploading mpl2kyhbp78ir9fgfc4dl8xcpxwsb86n-test-script (136B)15602026/09/21 12:57:18 OK 20260920000000_drop_claims.sql (29.1ms)15612026/09/21 12:57:18 goose: successfully migrated database to version: 2026092000000015622026/09/21 12:57:18 OK 1_commit_pending_closure.sql (2.08ms)15632026/09/21 12:57:18 OK 2_object_stats_trigger.sql (368.58µs)15642026/09/21 12:57:18 goose: up to current file version: 215652026/09/21 12:57:18 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"15662026/09/21 12:57:19 WARN Failed to register uploaded object key=log/iqd28xinri6q7bbc9w8ib18dlzcvdhhj-test-script.drv error="server returned 404: 404 page not found\n"15672026/09/21 12:57:19 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign15682026/09/21 12:57:19 WARN Failed to register uploaded object key=mpl2kyhbp78ir9fgfc4dl8xcpxwsb86n.ls error="server returned 404: 404 page not found\n"15692026/09/21 12:57:19 INFO Signed narinfos id=1 count=115702026/09/21 12:57:19 INFO Uploading 1 narinfos15712026/09/21 12:57:19 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete15722026/09/21 12:57:19 WARN Failed to register uploaded object key=mpl2kyhbp78ir9fgfc4dl8xcpxwsb86n.narinfo error="server returned 404: 404 page not found\n"15732026/09/21 12:57:19 INFO Completed upload id=115742026/09/21 12:57:19 INFO Upload complete. (299ms)1575=== NAME TestClientWithDependencies1576 client_integration_test.go:617: Skipping nix copy test - isolated store (/nix/var/nix/builds/nix-14861-3745989896/TestClientWithDependencies387885007/001/store) requires matching store prefix1577--- PASS: TestClientWithDependencies (3.70s)1578=== CONT TestService_AuthMiddleware_MTLSBoundSubjects1579--- PASS: TestReadProxy404 (1.20s)1580=== CONT TestResolveDBConnectionString1581=== RUN TestResolveDBConnectionString/flag_wins1582=== PAUSE TestResolveDBConnectionString/flag_wins1583=== RUN TestResolveDBConnectionString/file_when_flag_empty1584=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1585=== RUN TestResolveDBConnectionString/missing_file_is_an_error1586=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1587=== RUN TestResolveDBConnectionString/PGHOST_allows_empty1588=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1589=== RUN TestResolveDBConnectionString/nothing_configured1590=== PAUSE TestResolveDBConnectionString/nothing_configured1591=== CONT TestService_ReadAuthMiddleware15922026-09-21 12:57:19.169 UTC [18305] ERROR: relation "goose_db_version" does not exist at character 3615932026-09-21 12:57:19.169 UTC [18305] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15942026-09-21 12:57:19.199 UTC [18310] ERROR: relation "goose_db_version" does not exist at character 3615952026-09-21 12:57:19.199 UTC [18310] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15962026/09/21 12:57:19 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=015972026/09/21 12:57:19 INFO Vacuumed table table=pending_closures15982026/09/21 12:57:19 INFO Vacuumed table table=pending_objects15992026/09/21 12:57:19 INFO Vacuumed table table=multipart_uploads16002026/09/21 12:57:19 INFO Vacuumed table table=closures16012026/09/21 12:57:19 OK 20241026095416_initial_model.sql (43.55ms)16022026/09/21 12:57:19 OK 20251210153512_drop_unused_gin_index.sql (9.24ms)16032026/09/21 12:57:19 INFO Vacuumed table table=objects16042026/09/21 12:57:19 OK 20251218171726_add_pins.sql (36.46ms)16052026/09/21 12:57:19 OK 20241026095416_initial_model.sql (73.1ms)16062026/09/21 12:57:19 OK 20251210153512_drop_unused_gin_index.sql (7.94ms)16072026/09/21 12:57:19 OK 20260628120000_add_object_size_and_stats.sql (32.58ms)16082026/09/21 12:57:19 OK 20251218171726_add_pins.sql (26.56ms)16092026/09/21 12:57:19 OK 20260628120000_add_object_size_and_stats.sql (28.86ms)16102026/09/21 12:57:19 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=01611=== NAME TestPinProtectsFromGC1612 client_integration_test.go:794: Pin successfully protected closure from garbage collection16132026/09/21 12:57:19 OK 20260905000000_add_claims.sql (46.78ms)16142026/09/21 12:57:19 OK 20260920000000_drop_claims.sql (10.89ms)16152026/09/21 12:57:19 goose: successfully migrated database to version: 202609200000001616--- PASS: TestPinProtectsFromGC (4.74s)1617=== CONT TestService_RequireScope_OIDC16182026/09/21 12:57:19 OK 20260905000000_add_claims.sql (22.55ms)16192026/09/21 12:57:19 OK 1_commit_pending_closure.sql (2.83ms)16202026/09/21 12:57:19 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:57274/oidc16212026/09/21 12:57:19 OK 2_object_stats_trigger.sql (1.31ms)16222026/09/21 12:57:19 goose: up to current file version: 216232026/09/21 12:57:19 OK 20260920000000_drop_claims.sql (4.84ms)16242026/09/21 12:57:19 goose: successfully migrated database to version: 2026092000000016252026/09/21 12:57:19 OK 1_commit_pending_closure.sql (2.07ms)16262026/09/21 12:57:19 OK 2_object_stats_trigger.sql (614.5µs)16272026/09/21 12:57:19 goose: up to current file version: 216282026/09/21 12:57:19 INFO Aborted multipart uploads count=016292026/09/21 12:57:19 WARN Force mode enabled - objects will be deleted immediately without grace period16302026/09/21 12:57:19 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=016312026/09/21 12:57:19 INFO Vacuumed table table=pending_closures16322026/09/21 12:57:19 INFO Vacuumed table table=pending_objects16332026/09/21 12:57:19 INFO Vacuumed table table=multipart_uploads16342026/09/21 12:57:19 INFO Vacuumed table table=closures16352026/09/21 12:57:19 INFO Vacuumed table table=objects1636--- PASS: TestGCMetrics (1.34s)1637=== CONT TestService_AuthMiddleware_MTLSProxyHeader16382026-09-21 12:57:19.435 UTC [18314] ERROR: relation "goose_db_version" does not exist at character 3616392026-09-21 12:57:19.435 UTC [18314] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1640=== NAME TestClientCADerivations1641 client_ca_test.go:136: Built CA derivation: /nix/var/nix/builds/nix-14861-3745989896/TestClientCADerivations1722436901/001/store/55knn0zvizq6rg45wrqg4s979na2i10i-ca-test16422026/09/21 12:57:19 OK 20241026095416_initial_model.sql (121.5ms)16432026/09/21 12:57:19 OK 20251210153512_drop_unused_gin_index.sql (6.82ms)1644 client_ca_test.go:139: Found 1 dependencies (including self)16452026/09/21 12:57:19 OK 20251218171726_add_pins.sql (31.55ms)1646--- PASS: TestReadProxyConditionalGet (1.34s)1647=== CONT TestService_AuthMiddleware_OIDC16482026/09/21 12:57:19 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:57280/oidc16492026/09/21 12:57:19 OK 20260628120000_add_object_size_and_stats.sql (29.14ms)16502026/09/21 12:57:19 OK 20260905000000_add_claims.sql (43.21ms)16512026/09/21 12:57:19 OK 20260920000000_drop_claims.sql (38.27ms)16522026/09/21 12:57:19 goose: successfully migrated database to version: 2026092000000016532026/09/21 12:57:19 OK 1_commit_pending_closure.sql (2.36ms)16542026/09/21 12:57:19 OK 2_object_stats_trigger.sql (543.92µs)16552026/09/21 12:57:19 goose: up to current file version: 216562026/09/21 12:57:19 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"16572026-09-21 12:57:19.886 UTC [18331] ERROR: relation "goose_db_version" does not exist at character 3616582026-09-21 12:57:19.886 UTC [18331] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16592026/09/21 12:57:19 INFO Received uploads request method=POST path=/api/pending_closures16602026/09/21 12:57:19 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)16612026/09/21 12:57:19 INFO Uploading 55knn0zvizq6rg45wrqg4s979na2i10i-ca-test (144B)16622026/09/21 12:57:19 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"16632026/09/21 12:57:19 WARN Failed to register uploaded object key=log/pwh3awd5gxgvq5h544bm4vfqdm24vla7-ca-test.drv error="server returned 404: 404 page not found\n"16642026/09/21 12:57:19 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign16652026/09/21 12:57:19 WARN Failed to register uploaded object key=55knn0zvizq6rg45wrqg4s979na2i10i.ls error="server returned 404: 404 page not found\n"16662026/09/21 12:57:19 INFO Signed narinfos id=1 count=116672026/09/21 12:57:19 INFO Uploading 1 narinfos16682026/09/21 12:57:20 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete16692026/09/21 12:57:20 WARN Failed to register uploaded object key=55knn0zvizq6rg45wrqg4s979na2i10i.narinfo error="server returned 404: 404 page not found\n"16702026/09/21 12:57:20 INFO Completed upload id=116712026/09/21 12:57:20 INFO Upload complete. (321ms)16722026/09/21 12:57:20 INFO lead: acquired remote=192.0.2.1:123416732026/09/21 12:57:20 INFO lead: released remote=192.0.2.1:12341674--- PASS: TestLeadEndsOnShutdown (1.45s)1675=== CONT TestService_Rustfstest1676=== NAME TestClientCADerivations1677 client_ca_test.go:180: Narinfo contains CA field: StorePath: /nix/var/nix/builds/nix-14861-3745989896/TestClientCADerivations1722436901/001/store/55knn0zvizq6rg45wrqg4s979na2i10i-ca-test1678 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1679 Compression: zstd1680 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1681 NarSize: 1441682 References: 1683 Deriver: /nix/var/nix/builds/nix-14861-3745989896/TestClientCADerivations1722436901/001/store/pwh3awd5gxgvq5h544bm4vfqdm24vla7-ca-test.drv1684 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1685 client_ca_test.go:185: Checking for realisation files in S3...1686 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1687 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache16882026/09/21 12:57:20 OK 20241026095416_initial_model.sql (141.29ms)1689--- PASS: TestGCBugBareHashReferences (1.65s)1690=== CONT TestSkippedUploadsHandler16912026/09/21 12:57:20 INFO Client skipped oversized paths paths=3 nar_bytes=500000000016922026/09/21 12:57:20 OK 20251210153512_drop_unused_gin_index.sql (1.52ms)1693--- PASS: TestSkippedUploadsHandler (0.00s)1694=== CONT TestParseSize1695--- PASS: TestParseSize (0.00s)1696=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle16972026/09/21 12:57:20 OK 20251218171726_add_pins.sql (30.7ms)16982026/09/21 12:57:20 OK 20260628120000_add_object_size_and_stats.sql (21.49ms)16992026/09/21 12:57:20 OK 20260905000000_add_claims.sql (12.31ms)17002026/09/21 12:57:20 OK 20260920000000_drop_claims.sql (9.89ms)17012026/09/21 12:57:20 goose: successfully migrated database to version: 2026092000000017022026/09/21 12:57:20 OK 1_commit_pending_closure.sql (2.89ms)17032026/09/21 12:57:20 OK 2_object_stats_trigger.sql (868.5µs)17042026/09/21 12:57:20 goose: up to current file version: 21705=== NAME TestClientCADerivations1706 client_ca_test.go:258: nix copy output: error: binary cache 's3://bucket33?endpoint=http://localhost:57092®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/nix/var/nix/builds/nix-14861-3745989896/TestClientCADerivations1722436901/001/store'1707 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 11708--- PASS: TestClientCADerivations (3.58s)1709=== CONT TestCompletedNarNotReofferedAcrossClosures17102026-09-21 12:57:20.221 UTC [18340] ERROR: relation "goose_db_version" does not exist at character 3617112026-09-21 12:57:20.221 UTC [18340] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17122026-09-21 12:57:20.277 UTC [18342] ERROR: relation "goose_db_version" does not exist at character 3617132026-09-21 12:57:20.277 UTC [18342] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17142026/09/21 12:57:20 INFO lead: acquired remote=192.0.2.1:123417152026/09/21 12:57:20 OK 20241026095416_initial_model.sql (137.34ms)17162026/09/21 12:57:20 OK 20251210153512_drop_unused_gin_index.sql (2.08ms)17172026/09/21 12:57:20 OK 20241026095416_initial_model.sql (97.71ms)17182026/09/21 12:57:20 OK 20251218171726_add_pins.sql (15.93ms)17192026/09/21 12:57:20 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=017202026/09/21 12:57:20 OK 20251210153512_drop_unused_gin_index.sql (6.63ms)1721=== NAME TestClientIntegration1722 client_integration_test.go:323: Objects in database after GC:1723 client_integration_test.go:323: Successfully deleted all objects with GC --force17242026/09/21 12:57:20 OK 20260628120000_add_object_size_and_stats.sql (17.12ms)17252026/09/21 12:57:20 OK 20251218171726_add_pins.sql (11.78ms)1726--- PASS: TestClientIntegration (4.41s)1727=== CONT TestCacheConfigHandler1728=== RUN TestCacheConfigHandler/full_config,_no_issuer1729=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1730=== RUN TestCacheConfigHandler/no_cache_url_configured1731=== PAUSE TestCacheConfigHandler/no_cache_url_configured1732=== RUN TestCacheConfigHandler/no_signing_keys1733=== PAUSE TestCacheConfigHandler/no_signing_keys1734=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1735=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1736=== CONT TestPresignedUploadRegisteredBeforeCommit17372026/09/21 12:57:20 OK 20260628120000_add_object_size_and_stats.sql (22.28ms)17382026/09/21 12:57:20 OK 20260905000000_add_claims.sql (23.86ms)17392026/09/21 12:57:20 OK 20260920000000_drop_claims.sql (9.99ms)17402026/09/21 12:57:20 goose: successfully migrated database to version: 2026092000000017412026/09/21 12:57:20 OK 20260905000000_add_claims.sql (11.82ms)17422026/09/21 12:57:20 OK 1_commit_pending_closure.sql (2.58ms)17432026/09/21 12:57:20 OK 20260920000000_drop_claims.sql (2.22ms)17442026/09/21 12:57:20 goose: successfully migrated database to version: 2026092000000017452026/09/21 12:57:20 OK 2_object_stats_trigger.sql (1.22ms)17462026/09/21 12:57:20 goose: up to current file version: 217472026/09/21 12:57:20 OK 1_commit_pending_closure.sql (2.17ms)17482026/09/21 12:57:20 OK 2_object_stats_trigger.sql (634.83µs)17492026/09/21 12:57:20 goose: up to current file version: 217502026-09-21 12:57:20.525 UTC [18346] ERROR: relation "goose_db_version" does not exist at character 3617512026-09-21 12:57:20.525 UTC [18346] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17522026/09/21 12:57:20 INFO lead: released remote=192.0.2.1:123417532026-09-21 12:57:20.562 UTC [18347] ERROR: relation "goose_db_version" does not exist at character 3617542026-09-21 12:57:20.562 UTC [18347] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17552026/09/21 12:57:20 INFO lead: acquired remote=192.0.2.1:123417562026/09/21 12:57:20 INFO lead: released remote=192.0.2.1:12341757--- PASS: TestLeadElectsOneAndHandsOver (1.80s)1758=== CONT TestCompleteMultipartUpload_ErrorButObjectExists17592026/09/21 12:57:20 OK 20241026095416_initial_model.sql (70.3ms)17602026/09/21 12:57:20 OK 20251210153512_drop_unused_gin_index.sql (7.25ms)17612026/09/21 12:57:20 OK 20251218171726_add_pins.sql (10.65ms)17622026/09/21 12:57:20 OK 20260628120000_add_object_size_and_stats.sql (34.5ms)1763--- PASS: TestService_ReadAuthMiddleware (1.56s)1764=== CONT TestRedundantMultipartUpload17652026-09-21 12:57:20.701 UTC [18351] ERROR: relation "goose_db_version" does not exist at character 3617662026-09-21 12:57:20.701 UTC [18351] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17672026/09/21 12:57:20 OK 20260905000000_add_claims.sql (25.51ms)17682026/09/21 12:57:20 OK 20241026095416_initial_model.sql (81.34ms)17692026/09/21 12:57:20 OK 20260920000000_drop_claims.sql (3.02ms)17702026/09/21 12:57:20 goose: successfully migrated database to version: 2026092000000017712026/09/21 12:57:20 OK 20251210153512_drop_unused_gin_index.sql (1.26ms)17722026/09/21 12:57:20 OK 1_commit_pending_closure.sql (2.36ms)17732026/09/21 12:57:20 OK 20251218171726_add_pins.sql (2.89ms)17742026/09/21 12:57:20 OK 2_object_stats_trigger.sql (613.29µs)17752026/09/21 12:57:20 goose: up to current file version: 217762026/09/21 12:57:20 OK 20260628120000_add_object_size_and_stats.sql (14.7ms)17772026/09/21 12:57:20 OK 20260905000000_add_claims.sql (16.76ms)17782026/09/21 12:57:20 OK 20260920000000_drop_claims.sql (3.55ms)17792026/09/21 12:57:20 goose: successfully migrated database to version: 2026092000000017802026/09/21 12:57:20 OK 20241026095416_initial_model.sql (37.11ms)17812026/09/21 12:57:20 OK 1_commit_pending_closure.sql (2.09ms)17822026/09/21 12:57:20 OK 2_object_stats_trigger.sql (654.25µs)17832026/09/21 12:57:20 goose: up to current file version: 217842026/09/21 12:57:20 OK 20251210153512_drop_unused_gin_index.sql (8.66ms)17852026/09/21 12:57:20 OK 20251218171726_add_pins.sql (8.85ms)17862026/09/21 12:57:20 OK 20260628120000_add_object_size_and_stats.sql (14.87ms)17872026/09/21 12:57:20 OK 20260905000000_add_claims.sql (23ms)17882026/09/21 12:57:20 OK 20260920000000_drop_claims.sql (7.08ms)17892026/09/21 12:57:20 goose: successfully migrated database to version: 2026092000000017902026/09/21 12:57:20 OK 1_commit_pending_closure.sql (2.77ms)17912026/09/21 12:57:20 OK 2_object_stats_trigger.sql (581.33µs)17922026/09/21 12:57:20 goose: up to current file version: 217932026/09/21 12:57:20 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"17942026/09/21 12:57:20 WARN mTLS auth: bound subjects configured but subject DN unavailable17952026/09/21 12:57:20 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1796--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (1.74s)1797=== CONT TestService_ReadScope_PublicByDefault17982026-09-21 12:57:20.922 UTC [18357] ERROR: relation "goose_db_version" does not exist at character 3617992026-09-21 12:57:20.922 UTC [18357] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18002026-09-21 12:57:20.937 UTC [18358] ERROR: relation "goose_db_version" does not exist at character 3618012026-09-21 12:57:20.937 UTC [18358] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18022026/09/21 12:57:21 OK 20241026095416_initial_model.sql (68.63ms)18032026/09/21 12:57:21 OK 20251210153512_drop_unused_gin_index.sql (8.33ms)18042026/09/21 12:57:21 OK 20251218171726_add_pins.sql (30.79ms)18052026/09/21 12:57:21 OK 20241026095416_initial_model.sql (103.5ms)18062026/09/21 12:57:21 OK 20251210153512_drop_unused_gin_index.sql (2.6ms)1807=== RUN TestService_RequireScope_OIDC/builder_may_write1808=== PAUSE TestService_RequireScope_OIDC/builder_may_write1809=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1810=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1811=== RUN TestService_RequireScope_OIDC/ops_may_admin1812=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1813=== RUN TestService_RequireScope_OIDC/ops_may_not_write1814=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1815=== RUN TestService_RequireScope_OIDC/reader_may_not_write1816=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1817=== RUN TestService_RequireScope_OIDC/static_token_may_admin1818=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1819=== RUN TestService_RequireScope_OIDC/static_token_may_write1820=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1821=== RUN TestService_RequireScope_OIDC/reader_may_read1822=== PAUSE TestService_RequireScope_OIDC/reader_may_read1823=== RUN TestService_RequireScope_OIDC/writer_implies_read1824=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1825=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1826=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1827=== CONT TestProxyWriteTimeout/narinfo1828=== CONT TestProxyWriteTimeout/unknown_size1829=== CONT TestProxyWriteTimeout/10_GiB_nar1830=== CONT TestProxyWriteTimeout/1_GiB_nar1831--- PASS: TestProxyWriteTimeout (0.00s)1832 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1833 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1834 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1835 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1836=== CONT TestIsValidUploadKey/narinfo1837=== CONT TestIsValidUploadKey/realisation_plus_in_output1838=== CONT TestIsValidUploadKey/unknown_type1839=== CONT TestIsValidUploadKey/empty_key1840=== CONT TestIsValidUploadKey/absolute1841=== CONT TestIsValidUploadKey/traversal_nar1842=== CONT TestIsValidUploadKey/traversal1843=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1844=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1845=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1846=== CONT TestIsValidUploadKey/index.html1847=== CONT TestIsValidUploadKey/nix-cache-info1848=== CONT TestIsValidUploadKey/build_log_home-manager_file1849=== CONT TestIsValidUploadKey/realisation1850=== CONT TestIsValidUploadKey/build_log_equals1851=== CONT TestIsValidUploadKey/build_log_question_mark1852=== CONT TestIsValidUploadKey/build_log_plus_in_name1853=== CONT TestIsValidUploadKey/nar_plain1854=== CONT TestIsValidUploadKey/build_log1855=== CONT TestIsValidUploadKey/listing1856=== CONT TestIsValidUploadKey/nar_xz1857=== CONT TestIsValidUploadKey/nar_zst1858--- PASS: TestIsValidUploadKey (0.02s)1859 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1860 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1861 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1862 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1863 --- PASS: TestIsValidUploadKey/absolute (0.00s)1864 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1865 --- PASS: TestIsValidUploadKey/traversal (0.00s)1866 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1867 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1868 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1869 --- PASS: TestIsValidUploadKey/index.html (0.00s)1870 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1871 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1872 --- PASS: TestIsValidUploadKey/realisation (0.00s)1873 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1874 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1875 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1876 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1877 --- PASS: TestIsValidUploadKey/build_log (0.00s)1878 --- PASS: TestIsValidUploadKey/listing (0.00s)1879 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1880 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1881=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info18822026/09/21 12:57:21 INFO Received uploads request method=POST path=/1883=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key18842026/09/21 12:57:21 INFO Received complete multipart upload request method=POST path=/1885=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key18862026/09/21 12:57:21 INFO Received request for more parts method=POST path=/1887=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal18882026/09/21 12:57:21 INFO Received uploads request method=POST path=/1889--- PASS: TestUploadHandlersRejectInvalidKeys (0.02s)1890 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1891 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1892 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1893 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1894=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts18952026/09/21 12:57:21 INFO Received request for more parts method=POST path=/18962026/09/21 12:57:21 OK 20260628120000_add_object_size_and_stats.sql (27.15ms)18972026/09/21 12:57:21 OK 20251218171726_add_pins.sql (25.74ms)1898=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart18992026/09/21 12:57:21 INFO Received complete multipart upload request method=POST path=/19002026/09/21 12:57:21 OK 20260905000000_add_claims.sql (19.5ms)19012026/09/21 12:57:21 OK 20260628120000_add_object_size_and_stats.sql (18.02ms)19022026/09/21 12:57:21 OK 20260920000000_drop_claims.sql (1.89ms)19032026/09/21 12:57:21 goose: successfully migrated database to version: 2026092000000019042026/09/21 12:57:21 OK 1_commit_pending_closure.sql (2.18ms)19052026/09/21 12:57:21 OK 2_object_stats_trigger.sql (703.88µs)19062026/09/21 12:57:21 goose: up to current file version: 219072026/09/21 12:57:21 OK 20260905000000_add_claims.sql (12.45ms)19082026/09/21 12:57:21 OK 20260920000000_drop_claims.sql (6.96ms)19092026/09/21 12:57:21 goose: successfully migrated database to version: 202609200000001910=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure19112026/09/21 12:57:21 INFO Received uploads request method=POST path=/19122026-09-21 12:57:21.126 UTC [18359] ERROR: relation "goose_db_version" does not exist at character 3619132026-09-21 12:57:21.126 UTC [18359] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC19142026/09/21 12:57:21 OK 1_commit_pending_closure.sql (3.74ms)19152026/09/21 12:57:21 OK 2_object_stats_trigger.sql (633.38µs)19162026/09/21 12:57:21 goose: up to current file version: 219172026/09/21 12:57:21 OK 20241026095416_initial_model.sql (58.1ms)19182026/09/21 12:57:21 OK 20251210153512_drop_unused_gin_index.sql (6.89ms)19192026/09/21 12:57:21 OK 20251218171726_add_pins.sql (11.49ms)19202026/09/21 12:57:21 OK 20260628120000_add_object_size_and_stats.sql (22.39ms)19212026-09-21 12:57:21.241 UTC [18360] ERROR: relation "goose_db_version" does not exist at character 3619222026-09-21 12:57:21.241 UTC [18360] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1923--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (1.82s)1924=== CONT TestServerTLSConfig/no_client_CA1925=== CONT TestServerTLSConfig/not_a_PEM_file1926=== CONT TestServerTLSConfig/missing_CA_file1927--- PASS: TestServerTLSConfig (0.00s)1928 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1929 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)1930 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1931=== CONT TestIsValidCachePath/narinfo1932=== CONT TestIsValidCachePath/traversal_parent1933=== CONT TestIsValidCachePath/index.html1934=== CONT TestIsValidCachePath/nix-cache-info1935=== CONT TestIsValidCachePath/realisation1936=== CONT TestIsValidCachePath/log1937=== CONT TestIsValidCachePath/ls1938=== CONT TestIsValidCachePath/nar_uncompressed1939=== CONT TestIsValidCachePath/nar_bz21940=== CONT TestIsValidCachePath/traversal_in_middle1941=== CONT TestIsValidCachePath/nar_xz1942=== CONT TestIsValidCachePath/nar_zst1943=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1944=== CONT TestIsValidCachePath/empty1945=== CONT TestIsValidCachePath/short_hash1946=== CONT TestIsValidCachePath/wrong_extension1947=== CONT TestIsValidCachePath/leading_slash1948=== CONT TestIsValidCachePath/invalid_char_u1949=== CONT TestIsValidCachePath/random_path1950=== CONT TestIsValidCachePath/invalid_char_e1951--- PASS: TestIsValidCachePath (0.00s)1952 --- PASS: TestIsValidCachePath/narinfo (0.00s)1953 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1954 --- PASS: TestIsValidCachePath/index.html (0.00s)1955 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1956 --- PASS: TestIsValidCachePath/realisation (0.00s)1957 --- PASS: TestIsValidCachePath/log (0.00s)1958 --- PASS: TestIsValidCachePath/ls (0.00s)1959 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1960 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1961 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1962 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1963 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1964 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1965 --- PASS: TestIsValidCachePath/empty (0.00s)1966 --- PASS: TestIsValidCachePath/short_hash (0.00s)1967 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1968 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1969 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1970 --- PASS: TestIsValidCachePath/random_path (0.00s)1971 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1972=== CONT TestParseSingleRange/none1973=== CONT TestParseSingleRange/open-ended1974=== CONT TestParseSingleRange/start_far_past_EOF1975=== CONT TestParseSingleRange/start_past_EOF1976=== CONT TestParseSingleRange/single_byte1977=== CONT TestParseSingleRange/suffix_exceeds_size1978=== CONT TestParseSingleRange/suffix1979=== CONT TestParseSingleRange/end_clamped_to_size1980=== CONT TestParseSingleRange/malformed_both_empty1981=== CONT TestParseSingleRange/closed1982=== CONT TestParseSingleRange/malformed_end_before_start1983=== CONT TestParseSingleRange/multi-range_ignored1984=== CONT TestParseSingleRange/malformed_no_dash1985=== CONT TestParseSingleRange/unknown_unit1986--- PASS: TestParseSingleRange (0.00s)1987 --- PASS: TestParseSingleRange/none (0.00s)1988 --- PASS: TestParseSingleRange/open-ended (0.00s)1989 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1990 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1991 --- PASS: TestParseSingleRange/single_byte (0.00s)1992 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1993 --- PASS: TestParseSingleRange/suffix (0.00s)1994 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1995 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1996 --- PASS: TestParseSingleRange/closed (0.00s)1997 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1998 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1999 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)2000 --- PASS: TestParseSingleRange/unknown_unit (0.00s)2001=== CONT TestClientErrorHandling/InvalidStorePath20022026/09/21 12:57:21 OK 20260905000000_add_claims.sql (4.44ms)20032026/09/21 12:57:21 OK 20260920000000_drop_claims.sql (8.48ms)20042026/09/21 12:57:21 goose: successfully migrated database to version: 2026092000000020052026/09/21 12:57:21 OK 1_commit_pending_closure.sql (1.85ms)20062026/09/21 12:57:21 OK 2_object_stats_trigger.sql (594.17µs)20072026/09/21 12:57:21 goose: up to current file version: 220082026-09-21 12:57:21.295 UTC [18363] ERROR: relation "goose_db_version" does not exist at character 3620092026-09-21 12:57:21.295 UTC [18363] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC20102026/09/21 12:57:21 OK 20241026095416_initial_model.sql (46.42ms)20112026/09/21 12:57:21 OK 20251210153512_drop_unused_gin_index.sql (1.46ms)20122026/09/21 12:57:21 OK 20251218171726_add_pins.sql (7.75ms)20132026/09/21 12:57:21 OK 20260628120000_add_object_size_and_stats.sql (18.12ms)20142026/09/21 12:57:21 OK 20260905000000_add_claims.sql (17.21ms)20152026/09/21 12:57:21 OK 20260920000000_drop_claims.sql (14.08ms)20162026/09/21 12:57:21 goose: successfully migrated database to version: 2026092000000020172026/09/21 12:57:21 OK 1_commit_pending_closure.sql (2.57ms)20182026/09/21 12:57:21 OK 2_object_stats_trigger.sql (811.25µs)20192026/09/21 12:57:21 goose: up to current file version: 220202026-09-21 12:57:21.378 UTC [18364] ERROR: relation "goose_db_version" does not exist at character 3620212026-09-21 12:57:21.378 UTC [18364] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC20222026/09/21 12:57:21 OK 20241026095416_initial_model.sql (63.37ms)20232026/09/21 12:57:21 OK 20251210153512_drop_unused_gin_index.sql (9.96ms)2024=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token2025=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token2026=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected2027=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected2028=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected2029=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected2030=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2031=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2032=== CONT TestClientErrorHandling/ServerNotAvailable20332026/09/21 12:57:21 OK 20251218171726_add_pins.sql (11.03ms)20342026/09/21 12:57:21 OK 20260628120000_add_object_size_and_stats.sql (3.08ms)20352026/09/21 12:57:21 OK 20260905000000_add_claims.sql (15.33ms)20362026/09/21 12:57:21 OK 20260920000000_drop_claims.sql (8.88ms)20372026/09/21 12:57:21 goose: successfully migrated database to version: 2026092000000020382026/09/21 12:57:21 OK 1_commit_pending_closure.sql (2.05ms)20392026/09/21 12:57:21 OK 2_object_stats_trigger.sql (412.38µs)20402026/09/21 12:57:21 goose: up to current file version: 220412026/09/21 12:57:21 OK 20241026095416_initial_model.sql (40.28ms)20422026/09/21 12:57:21 OK 20251210153512_drop_unused_gin_index.sql (1.44ms)20432026/09/21 12:57:21 OK 20251218171726_add_pins.sql (3.48ms)20442026/09/21 12:57:21 OK 20260628120000_add_object_size_and_stats.sql (14.5ms)20452026/09/21 12:57:21 OK 20260905000000_add_claims.sql (13.5ms)20462026/09/21 12:57:21 OK 20260920000000_drop_claims.sql (14.7ms)20472026/09/21 12:57:21 goose: successfully migrated database to version: 2026092000000020482026/09/21 12:57:21 OK 1_commit_pending_closure.sql (1.8ms)20492026/09/21 12:57:21 OK 2_object_stats_trigger.sql (801.63µs)20502026/09/21 12:57:21 goose: up to current file version: 220512026-09-21 12:57:21.496 UTC [18367] ERROR: relation "goose_db_version" does not exist at character 3620522026-09-21 12:57:21.496 UTC [18367] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC20532026/09/21 12:57:21 INFO Received uploads request method=POST path=/api/pending_closures20542026/09/21 12:57:21 OK 20241026095416_initial_model.sql (41.96ms)20552026/09/21 12:57:21 OK 20251210153512_drop_unused_gin_index.sql (1.26ms)20562026/09/21 12:57:21 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/objects/present20572026/09/21 12:57:21 OK 20251218171726_add_pins.sql (24.38ms)20582026/09/21 12:57:21 OK 20260628120000_add_object_size_and_stats.sql (12.09ms)20592026/09/21 12:57:21 OK 20260905000000_add_claims.sql (12.35ms)20602026/09/21 12:57:21 OK 20260920000000_drop_claims.sql (25.3ms)20612026/09/21 12:57:21 goose: successfully migrated database to version: 2026092000000020622026/09/21 12:57:21 OK 1_commit_pending_closure.sql (2.24ms)20632026/09/21 12:57:21 OK 2_object_stats_trigger.sql (424.13µs)20642026/09/21 12:57:21 goose: up to current file version: 220652026/09/21 12:57:21 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=214.495803ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2066--- PASS: TestService_Rustfstest (1.67s)2067=== CONT TestClientErrorHandling/InvalidAuthToken20682026/09/21 12:57:21 INFO Received complete multipart upload request method=POST path=/api/multipart/complete20692026-09-21 12:57:21.800 UTC [18372] ERROR: relation "goose_db_version" does not exist at character 3620702026-09-21 12:57:21.800 UTC [18372] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC20712026/09/21 12:57:21 INFO Received uploads request method=POST path=/api/pending_closures20722026/09/21 12:57:21 OK 20241026095416_initial_model.sql (35.67ms)20732026/09/21 12:57:21 OK 20251210153512_drop_unused_gin_index.sql (1.16ms)20742026/09/21 12:57:21 OK 20251218171726_add_pins.sql (16.68ms)20752026/09/21 12:57:21 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=388.259356ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/objects/present20762026/09/21 12:57:21 OK 20260628120000_add_object_size_and_stats.sql (14.09ms)20772026/09/21 12:57:21 OK 20260905000000_add_claims.sql (1.71ms)20782026/09/21 12:57:21 OK 20260920000000_drop_claims.sql (7.75ms)20792026/09/21 12:57:21 goose: successfully migrated database to version: 2026092000000020802026/09/21 12:57:21 OK 1_commit_pending_closure.sql (2.23ms)20812026/09/21 12:57:21 OK 2_object_stats_trigger.sql (698.79µs)20822026/09/21 12:57:21 goose: up to current file version: 220832026/09/21 12:57:22 INFO Received uploads request method=POST path=/api/pending_closures20842026/09/21 12:57:22 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst20852026/09/21 12:57:22 INFO Received uploads request method=POST path=/api/pending_closures2086--- PASS: TestPresignedUploadRegisteredBeforeCommit (1.61s)2087=== CONT TestResolveDBConnectionString/flag_wins2088=== CONT TestResolveDBConnectionString/PGHOST_allows_empty2089=== CONT TestResolveDBConnectionString/nothing_configured2090=== CONT TestResolveDBConnectionString/missing_file_is_an_error2091=== CONT TestResolveDBConnectionString/file_when_flag_empty2092=== CONT TestCacheConfigHandler/full_config,_no_issuer2093=== CONT TestCacheConfigHandler/no_signing_keys2094=== CONT TestCacheConfigHandler/no_cache_url_configured2095=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator2096--- PASS: TestCacheConfigHandler (0.00s)2097 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)2098 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)2099 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)2100 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)2101=== CONT TestService_RequireScope_OIDC/builder_may_write2102=== CONT TestService_RequireScope_OIDC/static_token_may_admin2103=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read2104=== CONT TestService_RequireScope_OIDC/writer_implies_read2105=== CONT TestService_RequireScope_OIDC/reader_may_read2106=== CONT TestService_RequireScope_OIDC/static_token_may_write2107=== CONT TestService_RequireScope_OIDC/ops_may_not_write2108=== CONT TestService_RequireScope_OIDC/reader_may_not_write2109=== CONT TestService_RequireScope_OIDC/builder_may_not_admin2110=== CONT TestService_RequireScope_OIDC/ops_may_admin2111=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token2112--- PASS: TestResolveDBConnectionString (0.00s)2113 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)2114 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)2115 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)2116 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)2117 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)2118--- PASS: TestService_RequireScope_OIDC (1.67s)2119 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)2120 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)2121 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)2122 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)2123 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)2124 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)2125 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)2126 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)2127 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)2128 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)2129=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected21302026/09/21 12:57:22 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]2131=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2132=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected21332026/09/21 12:57:22 WARN Authentication failed token_preview=eyJhbGciOi...0R4_iwr3AQ token_length=702 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]2134--- PASS: TestService_AuthMiddleware_OIDC (1.76s)2135 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)2136 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)2137 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)2138 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)21392026/09/21 12:57:22 INFO Received uploads request method=POST path=/api/pending_closures21402026/09/21 12:57:22 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=795.726706ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/objects/present21412026-09-21 12:57:22.295 UTC [18373] ERROR: relation "goose_db_version" does not exist at character 3621422026-09-21 12:57:22.295 UTC [18373] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC2143--- PASS: TestUploadHandlersRejectOversizedBody (0.04s)2144 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.03s)2145 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.03s)2146 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (1.21s)21472026/09/21 12:57:22 INFO Received uploads request method=POST path=/api/pending_closures21482026/09/21 12:57:22 INFO Received complete multipart upload request method=POST path=/api/multipart/complete21492026/09/21 12:57:22 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=ZWEyYmY0Y2QtZDQzYi00MzRkLTlkMzEtNzBkMjgwZTU2YzEzLmQ0ZDAzZWY3LWI2MWYtNDQ0Yi04MDNiLTljMzc3OTA3NmI5NngxNzg5OTk1NDQyMTkxOTgxMDAw21502026/09/21 12:57:22 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=ZWEyYmY0Y2QtZDQzYi00MzRkLTlkMzEtNzBkMjgwZTU2YzEzLmQ0ZDAzZWY3LWI2MWYtNDQ0Yi04MDNiLTljMzc3OTA3NmI5NngxNzg5OTk1NDQyMTkxOTgxMDAw parts=12151--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (1.80s)21522026/09/21 12:57:22 INFO Received uploads request method=POST path=/api/pending_closures21532026/09/21 12:57:22 OK 20241026095416_initial_model.sql (111.93ms)21542026/09/21 12:57:22 OK 20251210153512_drop_unused_gin_index.sql (6.28ms)21552026/09/21 12:57:22 OK 20251218171726_add_pins.sql (28.27ms)21562026/09/21 12:57:22 OK 20260628120000_add_object_size_and_stats.sql (30ms)21572026/09/21 12:57:22 OK 20260905000000_add_claims.sql (43.39ms)21582026/09/21 12:57:22 OK 20260920000000_drop_claims.sql (17.54ms)21592026/09/21 12:57:22 goose: successfully migrated database to version: 202609200000002160--- PASS: TestService_ReadScope_PublicByDefault (1.72s)21612026/09/21 12:57:22 OK 1_commit_pending_closure.sql (2.23ms)21622026/09/21 12:57:22 OK 2_object_stats_trigger.sql (804.38µs)21632026/09/21 12:57:22 goose: up to current file version: 221642026/09/21 12:57:23 INFO Received complete multipart upload request method=POST path=/api/multipart/complete21652026/09/21 12:57:23 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.473869701s error="Post \"http://localhost:19999/api/objects/present\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/objects/present21662026/09/21 12:57:23 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=ZWEyYmY0Y2QtZDQzYi00MzRkLTlkMzEtNzBkMjgwZTU2YzEzLmU3MmZkZWNiLTFhZjktNDJmYi1hNDU0LTFlNWEwZTllNDliMHgxNzg5OTk1NDQxODY4NDYzMDAw parts=1221672026/09/21 12:57:23 INFO Received uploads request method=POST path=/api/pending_closures2168--- PASS: TestCompletedNarNotReofferedAcrossClosures (2.92s)21692026/09/21 12:57:23 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"21702026/09/21 12:57:23 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"21712026/09/21 12:57:23 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"21722026/09/21 12:57:23 INFO Received complete multipart upload request method=POST path=/api/multipart/complete21732026/09/21 12:57:23 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=ZWEyYmY0Y2QtZDQzYi00MzRkLTlkMzEtNzBkMjgwZTU2YzEzLjM1OTFlMDA4LTIxOGEtNGE0NS1hNDdlLTY4N2RmZGEyMmI4MngxNzg5OTk1NDQyMzg1MjMxMDAw parts=122174--- PASS: TestRedundantMultipartUpload (2.71s)21752026/09/21 12:57:24 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21762026/09/21 12:57:24 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=201.988349ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21772026/09/21 12:57:24 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=378.118607ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21782026/09/21 12:57:25 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=738.912846ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21792026/09/21 12:57:26 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.709398911s error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21802026/09/21 12:57:26 WARN Rate limiter enabled after throttle name=s3-test rate=521812026/09/21 12:57:26 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."2182=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle2183 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=102184 throttle_test.go:215: Rate limiter: enabled=true, rate=5.002185--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (6.60s)21862026/09/21 12:57: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 127.0.0.1:19999: connect: connection refused"21872026/09/21 12:57:27 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures21882026/09/21 12:57:27 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=202.406896ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures21892026/09/21 12:57:28 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=363.514058ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures21902026/09/21 12:57:28 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=725.906421ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures21912026/09/21 12:57:29 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.59901081s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2192--- PASS: TestClientErrorHandling (0.00s)2193 --- PASS: TestClientErrorHandling/InvalidStorePath (1.62s)2194 --- PASS: TestClientErrorHandling/InvalidAuthToken (1.66s)2195 --- PASS: TestClientErrorHandling/ServerNotAvailable (9.45s)2196PASS2197{"timestamp":"2026-09-21T12:57:30.858105Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:57181","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(7)"}21982026-09-21 12:57:30.963 UTC [16831] LOG: received smart shutdown request21992026-09-21 12:57:30.965 UTC [16831] LOG: background worker "logical replication launcher" (PID 16841) exited with exit code 122002026-09-21 12:57:30.974 UTC [16836] LOG: shutting down22012026-09-21 12:57:30.974 UTC [16836] LOG: checkpoint starting: shutdown immediate22022026-09-21 12:57:33.934 UTC [16836] LOG: checkpoint complete: wrote 13019 buffers (79.5%), wrote 3 SLRU buffers; 0 WAL file(s) added, 0 removed, 16 recycled; write=0.893 s, sync=2.042 s, total=2.961 s; sync files=18404, longest=0.183 s, average=0.001 s; distance=255511 kB, estimate=255511 kB; lsn=0/11112B78, redo lsn=0/11112B7822032026-09-21 12:57:33.982 UTC [16831] LOG: database system is shut down2204Running OIDC tests...2205=== RUN TestGlobMatch2206=== PAUSE TestGlobMatch2207=== RUN TestAudienceForIssuer2208=== PAUSE TestAudienceForIssuer2209=== RUN TestValidateToken_ValidToken2210=== PAUSE TestValidateToken_ValidToken2211=== RUN TestValidateToken_WrongAudience2212=== PAUSE TestValidateToken_WrongAudience2213=== RUN TestValidateToken_Expired2214=== PAUSE TestValidateToken_Expired2215=== RUN TestValidateToken_BoundClaimsMismatch2216=== PAUSE TestValidateToken_BoundClaimsMismatch2217=== RUN TestValidateToken_BoundSubjectMismatch2218=== PAUSE TestValidateToken_BoundSubjectMismatch2219=== RUN TestValidateToken_MultipleProviders2220=== PAUSE TestValidateToken_MultipleProviders2221=== RUN TestValidateToken_NoMatchingProvider2222=== PAUSE TestValidateToken_NoMatchingProvider2223=== RUN TestValidateToken_KubernetesServiceAccount2224=== PAUSE TestValidateToken_KubernetesServiceAccount2225=== RUN TestNewValidator_KubernetesRequiresCA2226=== PAUSE TestNewValidator_KubernetesRequiresCA2227=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2228=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2229=== RUN TestScopes_LegacyProviderDefaultsToWrite2230=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2231=== RUN TestScopes_Rules2232=== PAUSE TestScopes_Rules2233=== RUN TestScopes_ConfigValidation2234=== PAUSE TestScopes_ConfigValidation2235=== CONT TestGlobMatch2236=== RUN TestGlobMatch/foo_foo2237=== CONT TestScopes_LegacyProviderDefaultsToWrite2238=== CONT TestValidateToken_NoMatchingProvider2239=== PAUSE TestGlobMatch/foo_foo2240=== RUN TestGlobMatch/foo_bar2241=== PAUSE TestGlobMatch/foo_bar2242=== RUN TestGlobMatch/*_2243=== PAUSE TestGlobMatch/*_2244=== RUN TestGlobMatch/*_anything2245=== PAUSE TestGlobMatch/*_anything2246=== RUN TestGlobMatch/foo*_foo2247=== PAUSE TestGlobMatch/foo*_foo2248=== RUN TestGlobMatch/foo*_foobar2249=== PAUSE TestGlobMatch/foo*_foobar2250=== RUN TestGlobMatch/foo*_bar2251=== PAUSE TestGlobMatch/foo*_bar2252=== RUN TestGlobMatch/*bar_bar2253=== PAUSE TestGlobMatch/*bar_bar2254=== RUN TestGlobMatch/*bar_foobar2255=== PAUSE TestGlobMatch/*bar_foobar2256=== RUN TestGlobMatch/*bar_foo2257=== PAUSE TestGlobMatch/*bar_foo2258=== RUN TestGlobMatch/foo*bar_foobar2259=== PAUSE TestGlobMatch/foo*bar_foobar2260=== RUN TestGlobMatch/foo*bar_foo123bar2261=== PAUSE TestGlobMatch/foo*bar_foo123bar2262=== RUN TestGlobMatch/foo*bar_foobarbaz2263=== PAUSE TestGlobMatch/foo*bar_foobarbaz2264=== RUN TestGlobMatch/*/*_foo/bar2265=== PAUSE TestGlobMatch/*/*_foo/bar2266=== RUN TestGlobMatch/*/*_foo2267=== PAUSE TestGlobMatch/*/*_foo2268=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2269=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2270=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02271=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02272=== RUN TestGlobMatch/refs/*/main_refs/heads/main2273=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2274=== RUN TestGlobMatch/fo?_foo2275=== PAUSE TestGlobMatch/fo?_foo2276=== RUN TestGlobMatch/fo?_fo2277=== PAUSE TestGlobMatch/fo?_fo2278=== RUN TestGlobMatch/fo?_fooo2279=== PAUSE TestGlobMatch/fo?_fooo2280=== RUN TestGlobMatch/?oo_foo2281=== CONT TestValidateToken_WrongAudience2282=== CONT TestValidateToken_ValidToken2283=== CONT TestAudienceForIssuer2284--- PASS: TestAudienceForIssuer (0.00s)2285=== CONT TestScopes_Rules2286=== CONT TestValidateToken_BoundSubjectMismatch2287=== CONT TestValidateToken_MultipleProviders2288=== CONT TestValidateToken_BoundClaimsMismatch2289=== CONT TestScopes_ConfigValidation2290=== PAUSE TestGlobMatch/?oo_foo2291=== RUN TestGlobMatch/?oo_boo2292=== PAUSE TestGlobMatch/?oo_boo2293=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2294=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2295=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2296=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2297=== CONT TestNewValidator_KubernetesRequiresCA22982026/09/21 12:57:36 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:57354/oidc22992026/09/21 12:57:36 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:57353/oidc2300--- PASS: TestScopes_ConfigValidation (0.00s)2301=== CONT TestValidateToken_KubernetesIssuerFromOwnToken23022026/09/21 12:57:36 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:57355/oidc2303--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.01s)2304=== CONT TestValidateToken_KubernetesServiceAccount2305--- PASS: TestValidateToken_NoMatchingProvider (0.01s)2306=== CONT TestValidateToken_Expired23072026/09/21 12:57:36 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC12323082026/09/21 12:57:36 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:57359/oidc23092026/09/21 12:57:36 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:57356/oidc23102026/09/21 12:57:36 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:57358/oidc23112026/09/21 12:57:36 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:57357/oidc23122026/09/21 12:57:36 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:57352/oidc2313--- PASS: TestValidateToken_BoundClaimsMismatch (0.01s)2314=== CONT TestGlobMatch/foo_foo2315=== CONT TestGlobMatch/*bar_bar2316=== CONT TestGlobMatch/foo*bar_foobarbaz2317=== CONT TestGlobMatch/foo*bar_foo123bar2318=== CONT TestGlobMatch/foo*bar_foobar2319=== CONT TestGlobMatch/*bar_foo2320=== CONT TestGlobMatch/*bar_foobar2321=== CONT TestGlobMatch/fo?_fo2322=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2323=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2324=== CONT TestGlobMatch/?oo_boo2325=== CONT TestGlobMatch/foo*_foo2326=== CONT TestGlobMatch/?oo_foo2327=== CONT TestGlobMatch/fo?_fooo2328=== CONT TestGlobMatch/foo*_bar2329=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02330=== CONT TestGlobMatch/fo?_foo2331=== CONT TestGlobMatch/foo*_foobar2332=== CONT TestGlobMatch/refs/*/main_refs/heads/main2333=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2334=== CONT TestGlobMatch/*_2335=== CONT TestGlobMatch/*_anything2336=== CONT TestGlobMatch/foo_bar2337=== CONT TestGlobMatch/*/*_foo2338=== CONT TestGlobMatch/*/*_foo/bar2339--- PASS: TestGlobMatch (0.00s)2340 --- PASS: TestGlobMatch/foo_foo (0.00s)2341 --- PASS: TestGlobMatch/*bar_bar (0.00s)2342 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2343 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2344 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2345 --- PASS: TestGlobMatch/*bar_foo (0.00s)2346 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2347 --- PASS: TestGlobMatch/fo?_fo (0.00s)2348 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2349 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2350 --- PASS: TestGlobMatch/?oo_boo (0.00s)2351 --- PASS: TestGlobMatch/foo*_foo (0.00s)2352 --- PASS: TestGlobMatch/?oo_foo (0.00s)2353 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2354 --- PASS: TestGlobMatch/foo*_bar (0.00s)2355 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2356 --- PASS: TestGlobMatch/fo?_foo (0.00s)2357 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2358 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2359 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2360 --- PASS: TestGlobMatch/*_ (0.00s)2361 --- PASS: TestGlobMatch/*_anything (0.00s)2362 --- PASS: TestGlobMatch/foo_bar (0.00s)2363 --- PASS: TestGlobMatch/*/*_foo (0.00s)2364 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2365--- PASS: TestValidateToken_ValidToken (0.01s)23662026/09/21 12:57:36 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:57374/oidc23672026/09/21 12:57:36 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:57360/oidc2368--- PASS: TestValidateToken_BoundSubjectMismatch (0.01s)2369--- PASS: TestValidateToken_WrongAudience (0.01s)2370--- PASS: TestValidateToken_Expired (0.01s)23712026/09/21 12:57:36 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:573732372--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.01s)2373--- PASS: TestValidateToken_MultipleProviders (0.01s)2374--- PASS: TestScopes_Rules (0.01s)23752026/09/21 12:57:36 http: TLS handshake error from 127.0.0.1:57365: remote error: tls: bad certificate2376--- PASS: TestNewValidator_KubernetesRequiresCA (0.02s)2377--- PASS: TestValidateToken_KubernetesServiceAccount (0.01s)2378PASS2379Running hook tests...2380=== RUN TestSendPathsEmpty2381=== PAUSE TestSendPathsEmpty2382=== RUN TestQueueEnqueueAndFetch2383=== PAUSE TestQueueEnqueueAndFetch2384=== RUN TestQueueDeduplication2385=== PAUSE TestQueueDeduplication2386=== RUN TestQueueRemove2387=== PAUSE TestQueueRemove2388=== RUN TestQueueFetchBatchLimit2389=== PAUSE TestQueueFetchBatchLimit2390=== RUN TestQueueRetryMovesToBack2391=== PAUSE TestQueueRetryMovesToBack2392=== RUN TestQueueFetchRemoveLifecycle2393=== PAUSE TestQueueFetchRemoveLifecycle2394=== RUN TestQueueConcurrentWriters2395=== PAUSE TestQueueConcurrentWriters2396=== RUN TestQueueRemoveLargeClosure2397=== PAUSE TestQueueRemoveLargeClosure2398=== RUN TestServerClientIntegration2399=== PAUSE TestServerClientIntegration2400=== RUN TestServerQueueError2401=== PAUSE TestServerQueueError2402=== RUN TestGetListenerSocketActivation2403 server_test.go:210: === RUN TestGetListenerSocketActivation2404 --- PASS: TestGetListenerSocketActivation (0.00s)2405 PASS2406 2407--- PASS: TestGetListenerSocketActivation (0.02s)2408=== RUN TestDrainIsolatesPoisonPath2409=== PAUSE TestDrainIsolatesPoisonPath2410=== RUN TestRunNotBlockedByPoisonHead2411=== PAUSE TestRunNotBlockedByPoisonHead2412=== RUN TestDrainGivesUpWhenServerDown2413=== PAUSE TestDrainGivesUpWhenServerDown2414=== RUN TestFailedPathPrunedByLaterClosure2415=== PAUSE TestFailedPathPrunedByLaterClosure2416=== RUN TestWorkerUploadsAndRemoves2417=== PAUSE TestWorkerUploadsAndRemoves2418=== RUN TestWorkerSkipsGCdPaths2419=== PAUSE TestWorkerSkipsGCdPaths2420=== RUN TestWorkerPrunesClosureDeps2421=== PAUSE TestWorkerPrunesClosureDeps2422=== RUN TestDrainTimeout2423=== PAUSE TestDrainTimeout2424=== CONT TestSendPathsEmpty2425=== CONT TestServerQueueError2426=== CONT TestQueueRetryMovesToBack2427--- PASS: TestSendPathsEmpty (0.00s)2428=== CONT TestQueueFetchBatchLimit2429=== CONT TestQueueRemove2430=== CONT TestQueueDeduplication2431=== CONT TestQueueEnqueueAndFetch2432=== CONT TestWorkerUploadsAndRemoves2433=== CONT TestDrainTimeout2434=== CONT TestWorkerPrunesClosureDeps2435=== CONT TestWorkerSkipsGCdPaths24362026/09/21 12:57:36 ERROR Failed to queue paths error="permission denied" count=12437--- PASS: TestServerQueueError (0.00s)2438=== CONT TestDrainGivesUpWhenServerDown24392026/09/21 12:57:36 INFO Upload queue status pending=224402026/09/21 12:57:36 INFO Upload queue status pending=224412026/09/21 12:57:36 INFO Uploading batch count=224422026/09/21 12:57:36 WARN Store path no longer exists (garbage collected?), removing from queue path=/nix/var/nix/builds/nix-14861-3745989896/TestWorkerSkipsGCdPaths2659274754/002/nonexistent24432026/09/21 12:57:36 INFO Uploading batch count=224442026/09/21 12:57:36 INFO Uploading batch count=12445--- PASS: TestQueueFetchBatchLimit (0.01s)2446=== CONT TestFailedPathPrunedByLaterClosure2447--- PASS: TestQueueRemove (0.01s)2448=== CONT TestQueueConcurrentWriters24492026/09/21 12:57:36 INFO Uploading batch count=224502026/09/21 12:57:36 ERROR Upload failed error="upload failed" count=224512026/09/21 12:57:36 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-14861-3745989896/TestDrainGivesUpWhenServerDown3065443102/002/a24522026/09/21 12:57:36 INFO Upload queue status pending=224532026/09/21 12:57:36 INFO Uploading batch count=12454--- PASS: TestQueueEnqueueAndFetch (0.01s)2455=== CONT TestServerClientIntegration24562026/09/21 12:57:36 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-14861-3745989896/TestDrainGivesUpWhenServerDown3065443102/002/b2457--- PASS: TestQueueDeduplication (0.01s)2458=== CONT TestQueueFetchRemoveLifecycle24592026/09/21 12:57:36 INFO Uploading batch count=224602026/09/21 12:57:36 ERROR Upload failed error="upload failed" count=224612026/09/21 12:57:36 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-14861-3745989896/TestDrainGivesUpWhenServerDown3065443102/002/c2462--- PASS: TestQueueRetryMovesToBack (0.01s)2463=== CONT TestRunNotBlockedByPoisonHead24642026/09/21 12:57:36 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-14861-3745989896/TestDrainGivesUpWhenServerDown3065443102/002/d24652026/09/21 12:57:36 INFO Uploading batch count=224662026/09/21 12:57:36 ERROR Upload failed error="upload failed" count=224672026/09/21 12:57:36 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-14861-3745989896/TestDrainGivesUpWhenServerDown3065443102/002/e2468--- PASS: TestServerClientIntegration (0.00s)2469=== CONT TestDrainIsolatesPoisonPath24702026/09/21 12:57:36 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-14861-3745989896/TestDrainGivesUpWhenServerDown3065443102/002/f24712026/09/21 12:57:36 ERROR Drain finished with paths left in queue remaining=1024722026/09/21 12:57:36 INFO Uploading batch count=124732026/09/21 12:57:36 ERROR Upload failed error="upload failed" count=124742026/09/21 12:57:36 INFO Uploading batch count=12475--- PASS: TestDrainGivesUpWhenServerDown (0.01s)2476=== CONT TestQueueRemoveLargeClosure24772026/09/21 12:57:36 INFO Uploading batch count=124782026/09/21 12:57:36 INFO Uploading batch count=424792026/09/21 12:57:36 ERROR Upload failed error="upload failed" count=424802026/09/21 12:57:36 INFO Upload queue status pending=324812026/09/21 12:57:36 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-14861-3745989896/TestDrainIsolatesPoisonPath3409378346/002/bbb2482--- PASS: TestQueueFetchRemoveLifecycle (0.00s)24832026/09/21 12:57:36 INFO Uploading batch count=124842026/09/21 12:57:36 ERROR Upload failed error="upload failed" count=12485--- PASS: TestFailedPathPrunedByLaterClosure (0.01s)24862026/09/21 12:57:36 INFO Uploading batch count=124872026/09/21 12:57:36 ERROR Upload failed error="upload failed" count=124882026/09/21 12:57:36 INFO Uploading batch count=124892026/09/21 12:57:36 ERROR Upload failed error="upload failed" count=124902026/09/21 12:57:36 INFO Uploading batch count=124912026/09/21 12:57:36 ERROR Upload failed error="upload failed" count=124922026/09/21 12:57:36 ERROR Drain finished with paths left in queue remaining=12493--- PASS: TestDrainIsolatesPoisonPath (0.01s)2494--- PASS: TestWorkerSkipsGCdPaths (0.03s)2495--- PASS: TestWorkerUploadsAndRemoves (0.03s)2496--- PASS: TestWorkerPrunesClosureDeps (0.03s)2497--- PASS: TestQueueRemoveLargeClosure (0.06s)2498--- PASS: TestQueueConcurrentWriters (0.09s)24992026/09/21 12:57:37 ERROR Upload failed error="context deadline exceeded" count=225002026/09/21 12:57:37 ERROR Drain finished with paths left in queue remaining=42501--- PASS: TestDrainTimeout (0.21s)25022026/09/21 12:57:37 INFO Uploading batch count=125032026/09/21 12:57:37 INFO Uploading batch count=125042026/09/21 12:57:37 INFO Uploading batch count=125052026/09/21 12:57:37 ERROR Upload failed error="upload failed" count=125062026/09/21 12:57:37 INFO Uploading batch count=125072026/09/21 12:57:37 ERROR Upload failed error="upload failed" count=125082026/09/21 12:57:37 INFO Uploading batch count=125092026/09/21 12:57:37 ERROR Upload failed error="upload failed" count=125102026/09/21 12:57:37 INFO Uploading batch count=125112026/09/21 12:57:37 ERROR Upload failed error="upload failed" count=125122026/09/21 12:57:37 ERROR Drain finished with paths left in queue remaining=12513--- PASS: TestRunNotBlockedByPoisonHead (1.02s)2514PASS