niks3-go-unit-tests
checks.aarch64-darwin.go-unit-tests
· build #232
· raw
1Running client tests...2=== RUN TestDoServerRequestAttachesToken3=== PAUSE TestDoServerRequestAttachesToken4=== RUN TestRegisterUploadedObjectReusesConnections5=== PAUSE TestRegisterUploadedObjectReusesConnections6=== RUN TestCaseHackSuffix7=== PAUSE TestCaseHackSuffix8=== RUN TestFilterOversizedClosures9=== PAUSE TestFilterOversizedClosures10=== RUN TestPartSizeForNAR11=== PAUSE TestPartSizeForNAR12=== RUN TestUploadMultipart_SupersededByPeer13=== PAUSE TestUploadMultipart_SupersededByPeer14=== RUN TestDumpPathCaseHackMatchesNix15--- PASS: TestDumpPathCaseHackMatchesNix (0.05s)16=== RUN TestDumpPathCaseHackCollision17--- PASS: TestDumpPathCaseHackCollision (0.00s)18=== RUN TestDumpPathMatchesNix19=== PAUSE TestDumpPathMatchesNix20=== RUN TestDumpPathSingleFile21=== PAUSE TestDumpPathSingleFile22=== RUN TestDumpPathWriterError23=== PAUSE TestDumpPathWriterError24=== RUN TestEncodeNixBase3225=== PAUSE TestEncodeNixBase3226=== RUN TestEncodeNixBase32WithRealHash27=== PAUSE TestEncodeNixBase32WithRealHash28=== RUN TestConvertHashToNix3229=== PAUSE TestConvertHashToNix3230=== RUN TestGetStorePathHash31=== PAUSE TestGetStorePathHash32=== RUN TestPathInfoHashCompatibility33=== PAUSE TestPathInfoHashCompatibility34=== RUN TestParsePathInfoJSON35=== PAUSE TestParsePathInfoJSON36=== RUN TestParsePathInfoJSONMultiplePaths37=== PAUSE TestParsePathInfoJSONMultiplePaths38=== RUN TestPathInfoCACompatibility39=== PAUSE TestPathInfoCACompatibility40=== RUN TestRateLimiterFeedback41=== PAUSE TestRateLimiterFeedback42=== RUN TestRateLimiterFeedback_400DoesNotCountAsSuccess43=== PAUSE TestRateLimiterFeedback_400DoesNotCountAsSuccess44=== RUN TestResolveStorePath45=== PAUSE TestResolveStorePath46=== RUN TestDoWithRetry_BodyReplayedViaGetBody47=== PAUSE TestDoWithRetry_BodyReplayedViaGetBody48=== RUN TestShellSplit49=== PAUSE TestShellSplit50=== RUN TestShellSplitErrors51=== PAUSE TestShellSplitErrors52=== RUN TestStreamPushReportsEveryPath53=== PAUSE TestStreamPushReportsEveryPath54=== RUN TestStreamPushBatchesUnderLoad55=== PAUSE TestStreamPushBatchesUnderLoad56=== RUN TestStreamPushIsolatesFailures57=== PAUSE TestStreamPushIsolatesFailures58=== RUN TestStreamPushGivesUpOnDeadServer59=== PAUSE TestStreamPushGivesUpOnDeadServer60=== RUN TestStreamPushRequestLine61=== PAUSE TestStreamPushRequestLine62=== RUN TestSetClientTLS63=== PAUSE TestSetClientTLS64=== RUN TestSetClientTLSDoesNotMutateDefaultTransport65=== PAUSE TestSetClientTLSDoesNotMutateDefaultTransport66=== RUN TestSetClientTLSErrors67=== PAUSE TestSetClientTLSErrors68=== RUN TestStaticToken69=== PAUSE TestStaticToken70=== RUN TestFileTokenReadsAndCaches71=== PAUSE TestFileTokenReadsAndCaches72=== RUN TestFileTokenMissing73=== PAUSE TestFileTokenMissing74=== RUN TestFileTokenEmpty75=== PAUSE TestFileTokenEmpty76=== RUN TestScriptTokenNoExpiryRerunsEveryCall77=== PAUSE TestScriptTokenNoExpiryRerunsEveryCall78=== RUN TestScriptTokenCachesUntilRefresh79=== PAUSE TestScriptTokenCachesUntilRefresh80=== RUN TestScriptTokenEmptyToken81=== PAUSE TestScriptTokenEmptyToken82=== RUN TestScriptTokenBadJSON83=== PAUSE TestScriptTokenBadJSON84=== RUN TestScriptTokenScriptFails85=== PAUSE TestScriptTokenScriptFails86=== RUN TestScriptTokenEmptyCommand87=== PAUSE TestScriptTokenEmptyCommand88=== CONT TestDoServerRequestAttachesToken89=== CONT TestShellSplit90=== CONT TestStaticToken91=== CONT TestScriptTokenEmptyCommand92--- PASS: TestScriptTokenEmptyCommand (0.00s)93--- PASS: TestShellSplit (0.00s)94=== CONT TestFileTokenMissing95--- PASS: TestStaticToken (0.00s)96=== CONT TestScriptTokenEmptyToken97=== CONT TestScriptTokenBadJSON98=== CONT TestStreamPushGivesUpOnDeadServer99=== CONT TestScriptTokenCachesUntilRefresh100=== CONT TestScriptTokenNoExpiryRerunsEveryCall101--- PASS: TestFileTokenMissing (0.00s)102=== CONT TestSetClientTLSErrors1032026/09/21 13:24:19 ERROR Upload failed error="connection refused" count=20104=== CONT TestScriptTokenScriptFails1052026/09/21 13:24:19 ERROR Server seems unavailable, giving up on batch untried=17106=== CONT TestFileTokenEmpty107=== CONT TestFileTokenReadsAndCaches108--- PASS: TestFileTokenReadsAndCaches (0.00s)109=== CONT TestSetClientTLSDoesNotMutateDefaultTransport110--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)111=== CONT TestSetClientTLS112=== RUN TestSetClientTLSErrors/missing_cert_file113=== PAUSE TestSetClientTLSErrors/missing_cert_file114=== RUN TestSetClientTLSErrors/missing_key_file115=== PAUSE TestSetClientTLSErrors/missing_key_file116=== RUN TestSetClientTLSErrors/missing_ca_file117=== PAUSE TestSetClientTLSErrors/missing_ca_file118=== RUN TestSetClientTLSErrors/invalid_ca_file119=== PAUSE TestSetClientTLSErrors/invalid_ca_file120=== CONT TestStreamPushRequestLine121--- PASS: TestFileTokenEmpty (0.00s)122=== CONT TestStreamPushBatchesUnderLoad1232026/09/21 13:24:19 ERROR Upload failed error=boom count=1124--- PASS: TestDoServerRequestAttachesToken (0.01s)125=== CONT TestStreamPushIsolatesFailures1262026/09/21 13:24:19 ERROR Upload failed error="bad path" count=3127--- PASS: TestStreamPushIsolatesFailures (0.00s)128=== CONT TestConvertHashToNix32129=== RUN TestConvertHashToNix32/SRI_format_to_Nix32130=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32131=== RUN TestConvertHashToNix32/already_Nix32_format132=== PAUSE TestConvertHashToNix32/already_Nix32_format133=== RUN TestConvertHashToNix32/invalid_format134=== PAUSE TestConvertHashToNix32/invalid_format135=== CONT TestDoWithRetry_BodyReplayedViaGetBody136--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.00s)137=== CONT TestResolveStorePath138=== RUN TestSetClientTLS/rejects_connection_without_client_cert139=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert140=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA141=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA142=== RUN TestSetClientTLS/preserves_debug_logging_transport143=== PAUSE TestSetClientTLS/preserves_debug_logging_transport144=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess1452026/09/21 13:24:19 WARN Rate limiter enabled after throttle name=server-test rate=51462026/09/21 13:24:19 WARN Rate limiter enabled after throttle name=server-test rate=51472026/09/21 13:24:19 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:593441482026/09/21 13:24:19 WARN Rate limiter backed off name=server-test rate=51492026/09/21 13:24:19 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:59344150--- PASS: TestScriptTokenScriptFails (0.01s)151=== CONT TestRateLimiterFeedback152=== RUN TestRateLimiterFeedback/429_enables_limiter153=== PAUSE TestRateLimiterFeedback/429_enables_limiter154=== RUN TestRateLimiterFeedback/503_enables_limiter155=== PAUSE TestRateLimiterFeedback/503_enables_limiter156=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter157=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter158=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter159=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter160--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.00s)161=== CONT TestPathInfoCACompatibility162=== RUN TestPathInfoCACompatibility/null_ca_field163=== PAUSE TestPathInfoCACompatibility/null_ca_field164=== RUN TestPathInfoCACompatibility/old_string_format_-_text165=== CONT TestParsePathInfoJSONMultiplePaths166=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text167=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive168=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive169=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths170=== RUN TestPathInfoCACompatibility/new_structured_format_-_text171=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text172=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method173=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths174=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths175=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths176=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method177=== CONT TestParsePathInfoJSON178=== RUN TestParsePathInfoJSON/Nix_format179=== PAUSE TestParsePathInfoJSON/Nix_format180=== CONT TestPathInfoHashCompatibility181=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)182=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)183=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon184=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon185=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI186=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI187=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512188=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512189=== RUN TestParsePathInfoJSON/Lix_format190=== PAUSE TestParsePathInfoJSON/Lix_format191=== RUN TestParsePathInfoJSON/empty_input192=== PAUSE TestParsePathInfoJSON/empty_input193=== RUN TestParsePathInfoJSON/whitespace_only194=== PAUSE TestParsePathInfoJSON/whitespace_only195=== RUN TestParsePathInfoJSON/invalid_JSON196=== PAUSE TestParsePathInfoJSON/invalid_JSON197=== CONT TestGetStorePathHash198=== RUN TestGetStorePathHash/valid_store_path199=== PAUSE TestGetStorePathHash/valid_store_path200=== CONT TestDumpPathMatchesNix201=== RUN TestGetStorePathHash/basename_without_hyphen_should_error202=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error203=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error204=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error205=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error206=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error207=== CONT TestEncodeNixBase32WithRealHash208--- PASS: TestEncodeNixBase32WithRealHash (0.00s)209=== CONT TestEncodeNixBase32210=== RUN TestEncodeNixBase32/test_string_hash211=== PAUSE TestEncodeNixBase32/test_string_hash212=== RUN TestEncodeNixBase32/empty_input213--- PASS: TestResolveStorePath (0.00s)214=== CONT TestDumpPathWriterError215=== PAUSE TestEncodeNixBase32/empty_input216=== CONT TestDumpPathSingleFile217--- PASS: TestScriptTokenEmptyToken (0.01s)218=== CONT TestFilterOversizedClosures219=== RUN TestFilterOversizedClosures/no_limit_keeps_everything220=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything221=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped222=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped223=== RUN TestFilterOversizedClosures/all_closures_skipped224=== PAUSE TestFilterOversizedClosures/all_closures_skipped225=== CONT TestUploadMultipart_SupersededByPeer226=== RUN TestUploadMultipart_SupersededByPeer/exists227=== PAUSE TestUploadMultipart_SupersededByPeer/exists228=== RUN TestUploadMultipart_SupersededByPeer/missing229=== PAUSE TestUploadMultipart_SupersededByPeer/missing230=== CONT TestPartSizeForNAR231=== RUN TestPartSizeForNAR/zero_stays_at_minimum232=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum233=== RUN TestPartSizeForNAR/small_stays_at_minimum234=== PAUSE TestPartSizeForNAR/small_stays_at_minimum235=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum236=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum237=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts238=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts239=== RUN TestPartSizeForNAR/1_TiB240=== PAUSE TestPartSizeForNAR/1_TiB241=== RUN TestPartSizeForNAR/5_TiB_S3_max_object242=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object243=== RUN TestPartSizeForNAR/capped_at_5_GiB244=== PAUSE TestPartSizeForNAR/capped_at_5_GiB245=== CONT TestCaseHackSuffix246--- PASS: TestScriptTokenBadJSON (0.01s)247=== CONT TestStreamPushReportsEveryPath248--- PASS: TestStreamPushReportsEveryPath (0.00s)249=== CONT TestRegisterUploadedObjectReusesConnections250--- PASS: TestStreamPushRequestLine (0.02s)251=== CONT TestShellSplitErrors252--- PASS: TestShellSplitErrors (0.00s)253=== CONT TestSetClientTLSErrors/missing_cert_file254=== CONT TestSetClientTLSErrors/invalid_ca_file255=== CONT TestSetClientTLSErrors/missing_ca_file256=== CONT TestSetClientTLSErrors/missing_key_file257--- PASS: TestSetClientTLSErrors (0.00s)258 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)259 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)260 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)261 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)262=== CONT TestConvertHashToNix32/SRI_format_to_Nix32263=== CONT TestConvertHashToNix32/invalid_format264=== CONT TestConvertHashToNix32/already_Nix32_format265--- PASS: TestConvertHashToNix32 (0.00s)266 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)267 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)268 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)269=== CONT TestSetClientTLS/rejects_connection_without_client_cert270--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.03s)271=== CONT TestSetClientTLS/preserves_debug_logging_transport272--- PASS: TestScriptTokenCachesUntilRefresh (0.04s)273=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA274=== CONT TestRateLimiterFeedback/429_enables_limiter275=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter2762026/09/21 13:24:19 WARN Rate limiter enabled after throttle name=server-test rate=52772026/09/21 13:24:19 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:59416278=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter2792026/09/21 13:24:19 WARN Rate limiter backed off name=server-test rate=5280=== CONT TestRateLimiterFeedback/503_enables_limiter281=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths282=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths283--- PASS: TestParsePathInfoJSONMultiplePaths (0.00s)284 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)285 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)286=== CONT TestPathInfoCACompatibility/null_ca_field287=== CONT TestPathInfoCACompatibility/new_structured_format_-_text288=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive289=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method290=== CONT TestPathInfoCACompatibility/old_string_format_-_text291--- PASS: TestPathInfoCACompatibility (0.00s)292 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)293 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)294 --- PASS: TestPathInfoCACompatibility/old_2026/09/21 13:24:19 WARN Rate limiter enabled after throttle name=server-test rate=52952026/09/21 13:24:19 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:59422296string_format_-_fixed_recursive (0.00s)297 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)298 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)299=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)300=== CONT TestParsePathInfoJSON/Nix_format301=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512302=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI303=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon304--- PASS: TestPathInfoHashCompatibility (0.00s)305 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)306 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)307 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)308 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)309=== CONT TestParsePathInfoJSON/whitespace_only310=== CONT TestParsePathInfoJSON/invalid_JSON311=== CONT TestParsePathInfoJSON/empty_input312=== CONT TestParsePathInfoJSON/Lix_format313--- PASS: TestParsePathInfoJSON (0.00s)314 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)315 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)316 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)317 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)318 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)319=== CONT TestGetStorePathHash/valid_store_path320=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error321=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error322=== CONT TestGetStorePathHash/basename_without_hyphen_should_error323--- PASS: TestGetStorePathHash (0.00s)324 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)325 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)326 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)327 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)3282026/09/21 13:24:19 WARN Rate limiter backed off name=server-test rate=5329=== CONT TestEncodeNixBase32/empty_input3302026/09/21 13:24:19 http: TLS handshake error from 127.0.0.1:59413: remote error: tls: bad certificate331=== CONT TestFilterOversizedClosures/no_limit_keeps_everything332--- PASS: TestRateLimiterFeedback (0.00s)333 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)334 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)335 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)336 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)337=== CONT TestFilterOversizedClosures/all_closures_skipped3382026/09/21 13:24:19 WARN Skipping closure: path exceeds server max NAR size top_level_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper ove--- PASS: TestSetClientTLS (0.00s)339 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.00s)340 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.01s)341 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.02s)342rsized_path=/nix/store/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb-vm-image nar_size=5000 max_nar_size=50343=== CONT TestUploadMultipart_SupersededByPeer/exists344=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped3452026/09/21 13:24:19 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=2000346--- PASS: TestFilterOversizedClosures (0.00s)347 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)348 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)349 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)350=== CONT TestEncodeNixBase32/test_string_hash351=== CONT TestUploadMultipart_SupersededByPeer/missing352--- PASS: TestEncodeNixBase32 (0.00s)353 --- PASS: TestEncodeNixBase32/empty_input (0.00s)354 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)355=== CONT TestPartSizeForNAR/zero_stays_at_minimum356=== CONT TestPartSizeForNAR/1_TiB357=== CONT TestPartSizeForNAR/capped_at_5_GiB358=== CONT TestPartSizeForNAR/5_TiB_S3_max_object359=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum360=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts361=== CONT TestPartSizeForNAR/small_stays_at_minimum362--- PASS: TestPartSizeForNAR (0.00s)363 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)364 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)365 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)366 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)367 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)368 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)369 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)370--- PASS: TestUploadMultipart_SupersededByPeer (0.00s)371 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)372 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)373--- PASS: TestRegisterUploadedObjectReusesConnections (0.04s)374--- PASS: TestDumpPathWriterError (0.05s)375--- PASS: TestDumpPathSingleFile (0.05s)376--- PASS: TestCaseHackSuffix (0.05s)377--- PASS: TestDumpPathMatchesNix (0.08s)378--- PASS: TestStreamPushBatchesUnderLoad (0.10s)379--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)380PASS381Running server tests...382The files belonging to this database system will be owned by user "_nixbld10".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-38446-2842733125/postgres389796562/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-38446-2842733125/postgres389796562/data -l logfile start408409/nix/var/nix/builds/nix-38446-2842733125/postgres389796562:5432 - no response4102026-09-21 13:24:20.949 UTC [38529] LOG: starting PostgreSQL 18.6 on aarch64-apple-darwin25.6.0, compiled by clang version 21.1.8, 64-bit4112026-09-21 13:24:20.949 UTC [38529] LOG: listening on Unix socket "/nix/var/nix/builds/nix-38446-2842733125/postgres389796562/.s.PGSQL.5432"4122026-09-21 13:24:20.951 UTC [38537] LOG: database system was shut down at 2026-09-21 13:24:20 UTC4132026-09-21 13:24:20.952 UTC [38529] LOG: database system is ready to accept connections414/nix/var/nix/builds/nix-38446-2842733125/postgres389796562:5432 - accepting connections415=== RUN TestService_AuthMiddleware416=== PAUSE TestService_AuthMiddleware417=== RUN TestService_AuthMiddleware_MTLSProxyHeader418=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader419=== RUN TestService_AuthMiddleware_MTLSBoundSubjects420=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects421=== RUN TestService_ReadAuthMiddleware422=== PAUSE TestService_ReadAuthMiddleware423=== RUN TestService_AuthMiddleware_OIDC424=== PAUSE TestService_AuthMiddleware_OIDC425=== RUN TestService_RequireScope_OIDC426=== PAUSE TestService_RequireScope_OIDC427=== RUN TestService_ReadScope_PublicByDefault428=== PAUSE TestService_ReadScope_PublicByDefault429=== RUN TestCacheConfigHandler430=== PAUSE TestCacheConfigHandler431=== RUN TestCacheStatsHandler432=== PAUSE TestCacheStatsHandler433=== RUN TestClientCADerivations434=== PAUSE TestClientCADerivations435=== RUN TestClientErrorHandling436=== PAUSE TestClientErrorHandling437=== RUN TestClientIntegration438=== PAUSE TestClientIntegration439=== RUN TestClientMultipleUploads440=== PAUSE TestClientMultipleUploads441=== RUN TestClientWithDependencies442=== PAUSE TestClientWithDependencies443=== RUN TestClientSharedPathCommittedMidPush444=== PAUSE TestClientSharedPathCommittedMidPush445=== RUN TestPinProtectsFromGC446=== PAUSE TestPinProtectsFromGC447=== RUN TestResolveDBConnectionString448=== PAUSE TestResolveDBConnectionString449=== RUN TestLeadElectsOneAndHandsOver450=== PAUSE TestLeadElectsOneAndHandsOver451=== RUN TestLeadIncumbentWinsAfterRestart4522026-09-21 13:24:21.483 UTC [38620] ERROR: relation "goose_db_version" does not exist at character 364532026-09-21 13:24:21.483 UTC [38620] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC4542026/09/21 13:24:21 OK 20241026095416_initial_model.sql (6.01ms)4552026/09/21 13:24:21 OK 20251210153512_drop_unused_gin_index.sql (601.75µs)4562026/09/21 13:24:21 OK 20251218171726_add_pins.sql (1.36ms)4572026/09/21 13:24:21 OK 20260628120000_add_object_size_and_stats.sql (1.33ms)4582026/09/21 13:24:21 OK 20260905000000_add_claims.sql (1.38ms)4592026/09/21 13:24:21 OK 20260920000000_drop_claims.sql (847.29µs)4602026/09/21 13:24:21 goose: successfully migrated database to version: 202609200000004612026/09/21 13:24:21 OK 1_commit_pending_closure.sql (1.19ms)4622026/09/21 13:24:21 OK 2_object_stats_trigger.sql (291.33µs)4632026/09/21 13:24:21 goose: up to current file version: 24642026/09/21 13:24:21 INFO lead: acquired remote=192.0.2.1:12344652026/09/21 13:24:22 INFO lead: released remote=192.0.2.1:12344662026/09/21 13:24:22 INFO lead: acquired remote=192.0.2.1:12344672026/09/21 13:24:22 INFO lead: released remote=192.0.2.1:1234468--- PASS: TestLeadIncumbentWinsAfterRestart (1.05s)469=== RUN TestLeadEndsOnShutdown470=== PAUSE TestLeadEndsOnShutdown471=== RUN TestGCAdvisoryLockBlocksConcurrentRun4722026-09-21 13:24:22.304 UTC [38638] ERROR: relation "goose_db_version" does not exist at character 364732026-09-21 13:24:22.304 UTC [38638] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC4742026/09/21 13:24:22 OK 20241026095416_initial_model.sql (4.03ms)4752026/09/21 13:24:22 OK 20251210153512_drop_unused_gin_index.sql (419.21µs)4762026/09/21 13:24:22 OK 20251218171726_add_pins.sql (903.08µs)4772026/09/21 13:24:22 OK 20260628120000_add_object_size_and_stats.sql (915.42µs)4782026/09/21 13:24:22 OK 20260905000000_add_claims.sql (1.03ms)4792026/09/21 13:24:22 OK 20260920000000_drop_claims.sql (657.83µs)4802026/09/21 13:24:22 goose: successfully migrated database to version: 202609200000004812026/09/21 13:24:22 OK 1_commit_pending_closure.sql (889.75µs)4822026/09/21 13:24:22 OK 2_object_stats_trigger.sql (221.38µs)4832026/09/21 13:24:22 goose: up to current file version: 2484--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.16s)485=== RUN TestGCBugBareHashReferences486=== PAUSE TestGCBugBareHashReferences487=== RUN TestGCMetrics488=== PAUSE TestGCMetrics489=== RUN TestGCTaskStore_StartNew490=== PAUSE TestGCTaskStore_StartNew491=== RUN TestGCTaskStore_DeduplicateSameParams492=== PAUSE TestGCTaskStore_DeduplicateSameParams493=== RUN TestGCTaskStore_ConflictDifferentParams494=== PAUSE TestGCTaskStore_ConflictDifferentParams495=== RUN TestGCTaskStore_GetEmpty496=== PAUSE TestGCTaskStore_GetEmpty497=== RUN TestGCTaskStore_GetReturnsLatest498=== PAUSE TestGCTaskStore_GetReturnsLatest499=== RUN TestGCTaskStore_CompletedAllowsNewTask500=== PAUSE TestGCTaskStore_CompletedAllowsNewTask501=== RUN TestGCTaskStore_PhaseUpdates502=== PAUSE TestGCTaskStore_PhaseUpdates503=== RUN TestGCTaskStore_Fail504=== PAUSE TestGCTaskStore_Fail505=== RUN TestGracefulShutdownDrainsInflight506=== PAUSE TestGracefulShutdownDrainsInflight507=== RUN TestService_healthCheckHandler508=== PAUSE TestService_healthCheckHandler509=== RUN TestService_readinessHandler510=== PAUSE TestService_readinessHandler511=== RUN TestGenerateLandingPage512=== PAUSE TestGenerateLandingPage513=== RUN TestCacheConfigHandlerMaxNarSize514=== PAUSE TestCacheConfigHandlerMaxNarSize515=== RUN TestCreatePendingClosureRejectsOversizedNAR516=== PAUSE TestCreatePendingClosureRejectsOversizedNAR517=== RUN TestNARDeduplicationMetadataUploadBug518=== PAUSE TestNARDeduplicationMetadataUploadBug519=== RUN TestMetricsInventory520=== PAUSE TestMetricsInventory521=== RUN TestService_NativeMTLS522=== PAUSE TestService_NativeMTLS523=== RUN TestServerTLSConfig524=== PAUSE TestServerTLSConfig525=== RUN TestMultipartCleanup526=== PAUSE TestMultipartCleanup527=== RUN TestObjectStatsTrigger528=== PAUSE TestObjectStatsTrigger529=== RUN TestOrphanedObjectsGC530=== PAUSE TestOrphanedObjectsGC531=== RUN TestOrphanedObjectsGCStressTest532=== PAUSE TestOrphanedObjectsGCStressTest533=== RUN TestResurrectedObjectNotDeleted534=== PAUSE TestResurrectedObjectNotDeleted535=== RUN TestParseSingleRange536=== PAUSE TestParseSingleRange537=== RUN TestIsValidCachePath538=== PAUSE TestIsValidCachePath539=== RUN TestReadProxyNarinfo540=== PAUSE TestReadProxyNarinfo541=== RUN TestReadProxyNarinfoAlreadyDecompressed542=== PAUSE TestReadProxyNarinfoAlreadyDecompressed543=== RUN TestReadProxyNarStreaming544=== PAUSE TestReadProxyNarStreaming545=== RUN TestReadProxy404546=== PAUSE TestReadProxy404547=== RUN TestReadProxyInvalidPath548=== PAUSE TestReadProxyInvalidPath549=== RUN TestReadProxyHead550=== PAUSE TestReadProxyHead551=== RUN TestReadProxyConditionalGet552=== PAUSE TestReadProxyConditionalGet553=== RUN TestReadProxyRootRedirectsToIndexHTML554=== PAUSE TestReadProxyRootRedirectsToIndexHTML555=== RUN TestReadProxyDisabled556=== PAUSE TestReadProxyDisabled557=== RUN TestReadRedirectNar558=== PAUSE TestReadRedirectNar559=== RUN TestReadRedirectKeepsNarinfoProxied560=== PAUSE TestReadRedirectKeepsNarinfoProxied561=== RUN TestReadProxyRangeRequest562=== PAUSE TestReadProxyRangeRequest563=== RUN TestReadRedirectUsesPublicS3URL564=== PAUSE TestReadRedirectUsesPublicS3URL565=== RUN TestRedundantMultipartUpload566=== PAUSE TestRedundantMultipartUpload567=== RUN TestCompleteMultipartUpload_ErrorButObjectExists568=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists569=== RUN TestCompletedNarNotReofferedAcrossClosures570=== PAUSE TestCompletedNarNotReofferedAcrossClosures571=== RUN TestPresignedUploadRegisteredBeforeCommit572=== PAUSE TestPresignedUploadRegisteredBeforeCommit573=== RUN TestService_Rustfstest574=== PAUSE TestService_Rustfstest575=== RUN TestParseSize576=== PAUSE TestParseSize577=== RUN TestSkippedUploadsHandler578=== PAUSE TestSkippedUploadsHandler579=== RUN TestSystemdListenerNotActivated580--- PASS: TestSystemdListenerNotActivated (0.00s)581=== RUN TestWatchdogBeatsWhenHealthy582--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)583=== RUN TestWatchdogSkipsWhenUnhealthy5842026/09/21 13:24:22 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5852026/09/21 13:24:22 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5862026/09/21 13:24:22 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5872026/09/21 13:24:22 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5882026/09/21 13:24:22 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5892026/09/21 13:24:22 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5902026/09/21 13:24:22 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5912026/09/21 13:24:22 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5922026/09/21 13:24:22 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5932026/09/21 13:24:22 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"594--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)595=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle596=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle597=== RUN TestProxyWriteTimeout598=== PAUSE TestProxyWriteTimeout599=== RUN TestIsValidUploadKey600=== PAUSE TestIsValidUploadKey601=== RUN TestUploadHandlersRejectInvalidKeys602=== PAUSE TestUploadHandlersRejectInvalidKeys603=== RUN TestUploadHandlersRejectOversizedBody604=== PAUSE TestUploadHandlersRejectOversizedBody605=== RUN TestService_cleanupPendingClosuresHandler606=== PAUSE TestService_cleanupPendingClosuresHandler607=== RUN TestService_createPendingClosureHandler608=== PAUSE TestService_createPendingClosureHandler609=== RUN TestService_verifyS3Integrity610=== PAUSE TestService_verifyS3Integrity611=== RUN TestCompleteMultipartUnregistered612=== PAUSE TestCompleteMultipartUnregistered613=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT614=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT615=== CONT TestServerTLSConfig616=== CONT TestLeadElectsOneAndHandsOver617=== CONT TestLeadEndsOnShutdown618=== CONT TestClientCADerivations619=== RUN TestServerTLSConfig/no_client_CA620=== CONT TestService_AuthMiddleware621=== PAUSE TestServerTLSConfig/no_client_CA622=== RUN TestServerTLSConfig/missing_CA_file623=== PAUSE TestServerTLSConfig/missing_CA_file624=== RUN TestServerTLSConfig/not_a_PEM_file625=== PAUSE TestServerTLSConfig/not_a_PEM_file626=== CONT TestService_ReadScope_PublicByDefault627=== CONT TestService_NativeMTLS628=== CONT TestService_RequireScope_OIDC629=== CONT TestMetricsInventory630=== CONT TestCacheStatsHandler631=== CONT TestCacheConfigHandler632=== RUN TestCacheConfigHandler/full_config,_no_issuer633=== PAUSE TestCacheConfigHandler/full_config,_no_issuer634=== RUN TestCacheConfigHandler/no_cache_url_configured635=== PAUSE TestCacheConfigHandler/no_cache_url_configured636=== RUN TestCacheConfigHandler/no_signing_keys637=== PAUSE TestCacheConfigHandler/no_signing_keys638=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator639=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator640=== CONT TestReadProxyRangeRequest6412026/09/21 13:24:22 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:59444/oidc6422026-09-21 13:24:22.908 UTC [38666] ERROR: relation "goose_db_version" does not exist at character 366432026-09-21 13:24:22.908 UTC [38666] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6442026-09-21 13:24:22.909 UTC [38667] ERROR: relation "goose_db_version" does not exist at character 366452026-09-21 13:24:22.909 UTC [38667] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6462026-09-21 13:24:22.911 UTC [38668] ERROR: relation "goose_db_version" does not exist at character 366472026-09-21 13:24:22.911 UTC [38668] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6482026-09-21 13:24:22.911 UTC [38670] ERROR: relation "goose_db_version" does not exist at character 366492026-09-21 13:24:22.911 UTC [38670] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6502026-09-21 13:24:22.912 UTC [38669] ERROR: relation "goose_db_version" does not exist at character 366512026-09-21 13:24:22.912 UTC [38669] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6522026-09-21 13:24:22.913 UTC [38672] ERROR: relation "goose_db_version" does not exist at character 366532026-09-21 13:24:22.913 UTC [38672] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6542026-09-21 13:24:22.913 UTC [38671] ERROR: relation "goose_db_version" does not exist at character 366552026-09-21 13:24:22.913 UTC [38671] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6562026-09-21 13:24:22.913 UTC [38674] ERROR: relation "goose_db_version" does not exist at character 366572026-09-21 13:24:22.913 UTC [38674] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6582026-09-21 13:24:22.914 UTC [38673] ERROR: relation "goose_db_version" does not exist at character 366592026-09-21 13:24:22.914 UTC [38673] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6602026-09-21 13:24:22.915 UTC [38675] ERROR: relation "goose_db_version" does not exist at character 366612026-09-21 13:24:22.915 UTC [38675] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6622026/09/21 13:24:22 OK 20241026095416_initial_model.sql (7.84ms)6632026/09/21 13:24:22 OK 20241026095416_initial_model.sql (7.9ms)6642026/09/21 13:24:22 OK 20241026095416_initial_model.sql (8.37ms)6652026/09/21 13:24:22 OK 20241026095416_initial_model.sql (9.45ms)6662026/09/21 13:24:22 OK 20241026095416_initial_model.sql (10.6ms)6672026/09/21 13:24:22 OK 20241026095416_initial_model.sql (9.83ms)6682026/09/21 13:24:22 OK 20251210153512_drop_unused_gin_index.sql (896.71µs)6692026/09/21 13:24:22 OK 20251210153512_drop_unused_gin_index.sql (992.04µs)6702026/09/21 13:24:22 OK 20241026095416_initial_model.sql (8.85ms)6712026/09/21 13:24:22 OK 20251210153512_drop_unused_gin_index.sql (598.63µs)6722026/09/21 13:24:22 OK 20251210153512_drop_unused_gin_index.sql (762.46µs)6732026/09/21 13:24:22 OK 20251210153512_drop_unused_gin_index.sql (594.04µs)6742026/09/21 13:24:22 OK 20251210153512_drop_unused_gin_index.sql (868µs)6752026/09/21 13:24:22 OK 20241026095416_initial_model.sql (9.88ms)6762026/09/21 13:24:22 OK 20251210153512_drop_unused_gin_index.sql (883.5µs)6772026/09/21 13:24:22 OK 20241026095416_initial_model.sql (9.37ms)6782026/09/21 13:24:22 OK 20251218171726_add_pins.sql (1.39ms)6792026/09/21 13:24:22 OK 20251218171726_add_pins.sql (1.58ms)6802026/09/21 13:24:22 OK 20251210153512_drop_unused_gin_index.sql (789.13µs)6812026/09/21 13:24:22 OK 20251210153512_drop_unused_gin_index.sql (963.33µs)6822026/09/21 13:24:22 OK 20251218171726_add_pins.sql (1.58ms)6832026/09/21 13:24:22 OK 20251218171726_add_pins.sql (1.66ms)6842026/09/21 13:24:22 OK 20251218171726_add_pins.sql (1.69ms)6852026/09/21 13:24:22 OK 20241026095416_initial_model.sql (8.05ms)6862026/09/21 13:24:22 OK 20251218171726_add_pins.sql (2.19ms)6872026/09/21 13:24:22 OK 20251218171726_add_pins.sql (1.83ms)6882026/09/21 13:24:22 OK 20251218171726_add_pins.sql (1.29ms)6892026/09/21 13:24:22 OK 20251210153512_drop_unused_gin_index.sql (769.75µs)6902026/09/21 13:24:22 OK 20260628120000_add_object_size_and_stats.sql (1.79ms)6912026/09/21 13:24:22 OK 20251218171726_add_pins.sql (1.85ms)6922026/09/21 13:24:22 OK 20260628120000_add_object_size_and_stats.sql (2.44ms)6932026/09/21 13:24:22 OK 20260628120000_add_object_size_and_stats.sql (3.16ms)6942026/09/21 13:24:22 OK 20260628120000_add_object_size_and_stats.sql (1.15ms)6952026/09/21 13:24:22 OK 20260628120000_add_object_size_and_stats.sql (2.78ms)6962026/09/21 13:24:22 OK 20260628120000_add_object_size_and_stats.sql (2.29ms)6972026/09/21 13:24:22 OK 20260628120000_add_object_size_and_stats.sql (1.73ms)6982026/09/21 13:24:22 OK 20260628120000_add_object_size_and_stats.sql (2.7ms)6992026/09/21 13:24:22 OK 20260628120000_add_object_size_and_stats.sql (2.03ms)7002026/09/21 13:24:22 OK 20251218171726_add_pins.sql (3.87ms)7012026/09/21 13:24:22 OK 20260905000000_add_claims.sql (4.5ms)7022026/09/21 13:24:22 OK 20260905000000_add_claims.sql (3.34ms)7032026/09/21 13:24:22 OK 20260905000000_add_claims.sql (3.46ms)7042026/09/21 13:24:22 OK 20260905000000_add_claims.sql (3.62ms)7052026/09/21 13:24:22 OK 20260905000000_add_claims.sql (3.65ms)7062026/09/21 13:24:22 OK 20260905000000_add_claims.sql (3.69ms)7072026/09/21 13:24:22 OK 20260905000000_add_claims.sql (3.83ms)7082026/09/21 13:24:22 OK 20260905000000_add_claims.sql (3.94ms)7092026/09/21 13:24:22 OK 20260920000000_drop_claims.sql (1.01ms)7102026/09/21 13:24:22 goose: successfully migrated database to version: 202609200000007112026/09/21 13:24:22 OK 20260905000000_add_claims.sql (4ms)7122026/09/21 13:24:22 OK 20260920000000_drop_claims.sql (1.03ms)7132026/09/21 13:24:22 goose: successfully migrated database to version: 202609200000007142026/09/21 13:24:22 OK 20260628120000_add_object_size_and_stats.sql (2.17ms)7152026/09/21 13:24:22 OK 20260920000000_drop_claims.sql (1.03ms)7162026/09/21 13:24:22 goose: successfully migrated database to version: 202609200000007172026/09/21 13:24:22 OK 20260920000000_drop_claims.sql (1.16ms)7182026/09/21 13:24:22 goose: successfully migrated database to version: 202609200000007192026/09/21 13:24:22 OK 20260920000000_drop_claims.sql (1.68ms)7202026/09/21 13:24:22 goose: successfully migrated database to version: 202609200000007212026/09/21 13:24:22 OK 20260920000000_drop_claims.sql (1.44ms)7222026/09/21 13:24:22 goose: successfully migrated database to version: 202609200000007232026/09/21 13:24:22 OK 1_commit_pending_closure.sql (1.49ms)7242026/09/21 13:24:22 OK 20260920000000_drop_claims.sql (1.82ms)7252026/09/21 13:24:22 goose: successfully migrated database to version: 202609200000007262026/09/21 13:24:22 OK 20260920000000_drop_claims.sql (1.62ms)7272026/09/21 13:24:22 goose: successfully migrated database to version: 202609200000007282026/09/21 13:24:22 OK 20260920000000_drop_claims.sql (1.94ms)7292026/09/21 13:24:22 goose: successfully migrated database to version: 202609200000007302026/09/21 13:24:22 OK 20260905000000_add_claims.sql (1.68ms)7312026/09/21 13:24:22 OK 1_commit_pending_closure.sql (1.73ms)7322026/09/21 13:24:22 OK 1_commit_pending_closure.sql (1.89ms)7332026/09/21 13:24:22 OK 2_object_stats_trigger.sql (910.54µs)7342026/09/21 13:24:22 goose: up to current file version: 27352026/09/21 13:24:22 OK 1_commit_pending_closure.sql (1.22ms)7362026/09/21 13:24:22 OK 1_commit_pending_closure.sql (1.69ms)7372026/09/21 13:24:22 OK 1_commit_pending_closure.sql (1.41ms)7382026/09/21 13:24:22 OK 1_commit_pending_closure.sql (1.33ms)7392026/09/21 13:24:22 OK 2_object_stats_trigger.sql (320.63µs)7402026/09/21 13:24:22 goose: up to current file version: 27412026/09/21 13:24:22 OK 1_commit_pending_closure.sql (1.38ms)7422026/09/21 13:24:22 OK 2_object_stats_trigger.sql (693.46µs)7432026/09/21 13:24:22 goose: up to current file version: 27442026/09/21 13:24:22 OK 2_object_stats_trigger.sql (493.42µs)7452026/09/21 13:24:22 goose: up to current file version: 27462026/09/21 13:24:22 OK 2_object_stats_trigger.sql (407.67µs)7472026/09/21 13:24:22 goose: up to current file version: 27482026/09/21 13:24:22 OK 2_object_stats_trigger.sql (439.79µs)7492026/09/21 13:24:22 goose: up to current file version: 27502026/09/21 13:24:22 OK 2_object_stats_trigger.sql (591.92µs)7512026/09/21 13:24:22 goose: up to current file version: 27522026/09/21 13:24:22 OK 1_commit_pending_closure.sql (1.29ms)7532026/09/21 13:24:22 OK 20260920000000_drop_claims.sql (1.27ms)7542026/09/21 13:24:22 goose: successfully migrated database to version: 202609200000007552026/09/21 13:24:22 OK 2_object_stats_trigger.sql (495.88µs)7562026/09/21 13:24:22 goose: up to current file version: 27572026/09/21 13:24:22 OK 2_object_stats_trigger.sql (272.08µs)7582026/09/21 13:24:22 goose: up to current file version: 27592026/09/21 13:24:22 OK 1_commit_pending_closure.sql (765.88µs)7602026/09/21 13:24:22 OK 2_object_stats_trigger.sql (228.54µs)7612026/09/21 13:24:22 goose: up to current file version: 27622026/09/21 13:24:23 INFO lead: acquired remote=192.0.2.1:12347632026/09/21 13:24:23 INFO lead: released remote=192.0.2.1:1234764--- PASS: TestLeadEndsOnShutdown (0.45s)765=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT766--- PASS: TestReadProxyRangeRequest (0.58s)767=== CONT TestCompleteMultipartUnregistered768--- PASS: TestService_ReadScope_PublicByDefault (0.69s)769=== CONT TestService_verifyS3Integrity7702026/09/21 13:24:23 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"771--- PASS: TestService_AuthMiddleware (0.84s)772=== CONT TestService_createPendingClosureHandler7732026-09-21 13:24:23.520 UTC [38689] ERROR: relation "goose_db_version" does not exist at character 367742026-09-21 13:24:23.520 UTC [38689] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7752026-09-21 13:24:23.596 UTC [38690] ERROR: relation "goose_db_version" does not exist at character 367762026-09-21 13:24:23.596 UTC [38690] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7772026/09/21 13:24:23 OK 20241026095416_initial_model.sql (56.14ms)7782026/09/21 13:24:23 OK 20251210153512_drop_unused_gin_index.sql (956.63µs)779--- PASS: TestMetricsInventory (1.00s)780=== CONT TestService_cleanupPendingClosuresHandler7812026/09/21 13:24:23 OK 20251218171726_add_pins.sql (16.33ms)7822026/09/21 13:24:23 OK 20260628120000_add_object_size_and_stats.sql (19.26ms)7832026/09/21 13:24:23 OK 20260905000000_add_claims.sql (8.4ms)7842026/09/21 13:24:23 OK 20260920000000_drop_claims.sql (8.62ms)7852026/09/21 13:24:23 goose: successfully migrated database to version: 202609200000007862026/09/21 13:24:23 OK 1_commit_pending_closure.sql (971.33µs)7872026/09/21 13:24:23 OK 2_object_stats_trigger.sql (240.08µs)7882026/09/21 13:24:23 goose: up to current file version: 27892026-09-21 13:24:23.657 UTC [38694] ERROR: relation "goose_db_version" does not exist at character 367902026-09-21 13:24:23.657 UTC [38694] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7912026/09/21 13:24:23 OK 20241026095416_initial_model.sql (49.03ms)7922026/09/21 13:24:23 OK 20251210153512_drop_unused_gin_index.sql (6.9ms)7932026/09/21 13:24:23 OK 20251218171726_add_pins.sql (7.25ms)7942026/09/21 13:24:23 OK 20260628120000_add_object_size_and_stats.sql (7.57ms)7952026/09/21 13:24:23 OK 20260905000000_add_claims.sql (32.07ms)7962026/09/21 13:24:23 OK 20241026095416_initial_model.sql (47.32ms)7972026/09/21 13:24:23 OK 20251210153512_drop_unused_gin_index.sql (11.04ms)7982026/09/21 13:24:23 OK 20260920000000_drop_claims.sql (22.35ms)7992026/09/21 13:24:23 goose: successfully migrated database to version: 202609200000008002026/09/21 13:24:23 OK 1_commit_pending_closure.sql (1.32ms)8012026/09/21 13:24:23 OK 2_object_stats_trigger.sql (275.71µs)8022026/09/21 13:24:23 goose: up to current file version: 28032026/09/21 13:24:23 OK 20251218171726_add_pins.sql (17.53ms)8042026/09/21 13:24:23 OK 20260628120000_add_object_size_and_stats.sql (1.53ms)8052026/09/21 13:24:23 OK 20260905000000_add_claims.sql (8.28ms)806--- PASS: TestCacheStatsHandler (1.16s)807=== CONT TestUploadHandlersRejectOversizedBody8082026/09/21 13:24:23 OK 20260920000000_drop_claims.sql (12.48ms)8092026/09/21 13:24:23 goose: successfully migrated database to version: 202609200000008102026/09/21 13:24:23 OK 1_commit_pending_closure.sql (1.41ms)8112026/09/21 13:24:23 OK 2_object_stats_trigger.sql (340.54µs)8122026/09/21 13:24:23 goose: up to current file version: 2813=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure814=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure815=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart816=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart817=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts818=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts819=== CONT TestUploadHandlersRejectInvalidKeys820=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info821=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info822=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal823=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal824=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key825=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key826=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key827=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key828=== CONT TestIsValidUploadKey829=== RUN TestIsValidUploadKey/narinfo830=== PAUSE TestIsValidUploadKey/narinfo831=== RUN TestIsValidUploadKey/nar_zst832=== PAUSE TestIsValidUploadKey/nar_zst833=== RUN TestIsValidUploadKey/nar_xz834=== PAUSE TestIsValidUploadKey/nar_xz835=== RUN TestIsValidUploadKey/nar_plain836=== PAUSE TestIsValidUploadKey/nar_plain837=== RUN TestIsValidUploadKey/listing838=== PAUSE TestIsValidUploadKey/listing839=== RUN TestIsValidUploadKey/build_log840=== PAUSE TestIsValidUploadKey/build_log841=== RUN TestIsValidUploadKey/build_log_home-manager_file842=== PAUSE TestIsValidUploadKey/build_log_home-manager_file843=== RUN TestIsValidUploadKey/build_log_plus_in_name844=== PAUSE TestIsValidUploadKey/build_log_plus_in_name845=== RUN TestIsValidUploadKey/build_log_question_mark846=== PAUSE TestIsValidUploadKey/build_log_question_mark847=== RUN TestIsValidUploadKey/build_log_equals848=== PAUSE TestIsValidUploadKey/build_log_equals849=== RUN TestIsValidUploadKey/realisation850=== PAUSE TestIsValidUploadKey/realisation851=== RUN TestIsValidUploadKey/realisation_plus_in_output852=== PAUSE TestIsValidUploadKey/realisation_plus_in_output853=== RUN TestIsValidUploadKey/nix-cache-info854=== PAUSE TestIsValidUploadKey/nix-cache-info855=== RUN TestIsValidUploadKey/index.html856=== PAUSE TestIsValidUploadKey/index.html857=== RUN TestIsValidUploadKey/narinfo_key,_nar_type858=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type859=== RUN TestIsValidUploadKey/nar_key,_narinfo_type860=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type861=== RUN TestIsValidUploadKey/listing_key,_narinfo_type862=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type863=== RUN TestIsValidUploadKey/traversal864=== PAUSE TestIsValidUploadKey/traversal865=== RUN TestIsValidUploadKey/traversal_nar866=== PAUSE TestIsValidUploadKey/traversal_nar867=== RUN TestIsValidUploadKey/absolute868=== PAUSE TestIsValidUploadKey/absolute869=== RUN TestIsValidUploadKey/empty_key870=== PAUSE TestIsValidUploadKey/empty_key871=== RUN TestIsValidUploadKey/unknown_type872=== PAUSE TestIsValidUploadKey/unknown_type873=== CONT TestProxyWriteTimeout874=== RUN TestProxyWriteTimeout/narinfo875=== PAUSE TestProxyWriteTimeout/narinfo876=== RUN TestProxyWriteTimeout/1_GiB_nar877=== PAUSE TestProxyWriteTimeout/1_GiB_nar878=== RUN TestProxyWriteTimeout/10_GiB_nar879=== PAUSE TestProxyWriteTimeout/10_GiB_nar880=== RUN TestProxyWriteTimeout/unknown_size881=== PAUSE TestProxyWriteTimeout/unknown_size882=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle8832026-09-21 13:24:23.820 UTC [38697] ERROR: relation "goose_db_version" does not exist at character 368842026-09-21 13:24:23.820 UTC [38697] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8852026/09/21 13:24:23 OK 20241026095416_initial_model.sql (47.93ms)8862026/09/21 13:24:23 OK 20251210153512_drop_unused_gin_index.sql (653.63µs)8872026/09/21 13:24:23 OK 20251218171726_add_pins.sql (11.68ms)8882026/09/21 13:24:23 OK 20260628120000_add_object_size_and_stats.sql (10.49ms)8892026/09/21 13:24:23 OK 20260905000000_add_claims.sql (10.9ms)8902026/09/21 13:24:23 OK 20260920000000_drop_claims.sql (11.02ms)8912026/09/21 13:24:23 goose: successfully migrated database to version: 202609200000008922026/09/21 13:24:23 OK 1_commit_pending_closure.sql (1.07ms)8932026/09/21 13:24:23 OK 2_object_stats_trigger.sql (435.42µs)8942026/09/21 13:24:23 goose: up to current file version: 28952026/09/21 13:24:24 INFO lead: acquired remote=192.0.2.1:1234896=== RUN TestService_RequireScope_OIDC/builder_may_write897=== PAUSE TestService_RequireScope_OIDC/builder_may_write898=== RUN TestService_RequireScope_OIDC/builder_may_not_admin899=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin900=== RUN TestService_RequireScope_OIDC/ops_may_admin901=== PAUSE TestService_RequireScope_OIDC/ops_may_admin902=== RUN TestService_RequireScope_OIDC/ops_may_not_write903=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write904=== RUN TestService_RequireScope_OIDC/reader_may_not_write905=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write906=== RUN TestService_RequireScope_OIDC/static_token_may_admin907=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin908=== RUN TestService_RequireScope_OIDC/static_token_may_write909=== PAUSE TestService_RequireScope_OIDC/static_token_may_write910=== RUN TestService_RequireScope_OIDC/reader_may_read911=== PAUSE TestService_RequireScope_OIDC/reader_may_read912=== RUN TestService_RequireScope_OIDC/writer_implies_read913=== PAUSE TestService_RequireScope_OIDC/writer_implies_read914=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read915=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read916=== CONT TestSkippedUploadsHandler9172026/09/21 13:24:24 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000918--- PASS: TestSkippedUploadsHandler (0.00s)919=== CONT TestParseSize920--- PASS: TestParseSize (0.00s)921=== CONT TestService_Rustfstest9222026-09-21 13:24:24.142 UTC [38706] ERROR: relation "goose_db_version" does not exist at character 369232026-09-21 13:24:24.142 UTC [38706] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9242026/09/21 13:24:24 INFO lead: released remote=192.0.2.1:1234925=== NAME TestClientCADerivations926 client_ca_test.go:136: Built CA derivation: /nix/var/nix/builds/nix-38446-2842733125/TestClientCADerivations740139489/001/store/gi06vqybr0yj0ymgjnsfa8b1vwanbk8l-ca-test9272026/09/21 13:24:24 INFO lead: acquired remote=192.0.2.1:12349282026/09/21 13:24:24 INFO lead: released remote=192.0.2.1:1234929--- PASS: TestLeadElectsOneAndHandsOver (1.60s)930=== CONT TestPresignedUploadRegisteredBeforeCommit931=== NAME TestClientCADerivations932 client_ca_test.go:139: Found 1 dependencies (including self)9332026/09/21 13:24:24 WARN mTLS auth: subject not in bound subjects subject="CN=reader"9342026/09/21 13:24:24 WARN mTLS auth: subject not in bound subjects subject="CN=reader"935--- PASS: TestService_NativeMTLS (1.62s)936=== CONT TestCompletedNarNotReofferedAcrossClosures9372026/09/21 13:24:24 OK 20241026095416_initial_model.sql (61.06ms)9382026/09/21 13:24:24 OK 20251210153512_drop_unused_gin_index.sql (1.49ms)9392026/09/21 13:24:24 OK 20251218171726_add_pins.sql (17.29ms)9402026/09/21 13:24:24 OK 20260628120000_add_object_size_and_stats.sql (8ms)9412026/09/21 13:24:24 OK 20260905000000_add_claims.sql (24.1ms)9422026-09-21 13:24:24.278 UTC [38717] ERROR: relation "goose_db_version" does not exist at character 369432026-09-21 13:24:24.278 UTC [38717] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9442026/09/21 13:24:24 OK 20260920000000_drop_claims.sql (12.32ms)9452026/09/21 13:24:24 goose: successfully migrated database to version: 202609200000009462026/09/21 13:24:24 OK 1_commit_pending_closure.sql (1.05ms)9472026/09/21 13:24:24 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"9482026/09/21 13:24:24 OK 2_object_stats_trigger.sql (244.29µs)9492026/09/21 13:24:24 goose: up to current file version: 29502026/09/21 13:24:24 INFO Received uploads request method=POST path=/api/pending_closures9512026/09/21 13:24:24 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)9522026/09/21 13:24:24 INFO Uploading gi06vqybr0yj0ymgjnsfa8b1vwanbk8l-ca-test (144B)9532026/09/21 13:24:24 INFO Received uploads request method=POST path=/api/pending_closures9542026/09/21 13:24:24 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"9552026/09/21 13:24:24 WARN Failed to register uploaded object key=gi06vqybr0yj0ymgjnsfa8b1vwanbk8l.ls error="server returned 404: 404 page not found\n"9562026/09/21 13:24:24 WARN Failed to register uploaded object key=log/c54dzflfg20f1nanrd4s35sgzw1jc2ff-ca-test.drv error="server returned 404: 404 page not found\n"9572026/09/21 13:24:24 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign9582026/09/21 13:24:24 INFO Signed narinfos id=1 count=19592026/09/21 13:24:24 INFO Uploading 1 narinfos9602026/09/21 13:24:24 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete9612026/09/21 13:24:24 WARN Failed to register uploaded object key=gi06vqybr0yj0ymgjnsfa8b1vwanbk8l.narinfo error="server returned 404: 404 page not found\n"9622026/09/21 13:24:24 OK 20241026095416_initial_model.sql (52.96ms)9632026/09/21 13:24:24 OK 20251210153512_drop_unused_gin_index.sql (10.51ms)9642026/09/21 13:24:24 INFO Completed upload id=19652026/09/21 13:24:24 INFO Upload complete. (139ms)9662026/09/21 13:24:24 OK 20251218171726_add_pins.sql (10.54ms)967=== NAME TestClientCADerivations968 client_ca_test.go:180: Narinfo contains CA field: StorePath: /nix/var/nix/builds/nix-38446-2842733125/TestClientCADerivations740139489/001/store/gi06vqybr0yj0ymgjnsfa8b1vwanbk8l-ca-test969 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst970 Compression: zstd971 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n972 NarSize: 144973 References: 974 Deriver: /nix/var/nix/builds/nix-38446-2842733125/TestClientCADerivations740139489/001/store/c54dzflfg20f1nanrd4s35sgzw1jc2ff-ca-test.drv975 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n976 client_ca_test.go:185: Checking for realisation files in S3...977--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (1.33s)978=== CONT TestCompleteMultipartUpload_ErrorButObjectExists979=== NAME TestClientCADerivations980 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations981 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache9822026/09/21 13:24:24 OK 20260628120000_add_object_size_and_stats.sql (14.24ms)9832026/09/21 13:24:24 OK 20260905000000_add_claims.sql (17.34ms)9842026/09/21 13:24:24 OK 20260920000000_drop_claims.sql (6.46ms)9852026/09/21 13:24:24 goose: successfully migrated database to version: 202609200000009862026/09/21 13:24:24 OK 1_commit_pending_closure.sql (1.13ms)9872026/09/21 13:24:24 OK 2_object_stats_trigger.sql (193.75µs)9882026/09/21 13:24:24 goose: up to current file version: 2989 client_ca_test.go:258: nix copy output: error: binary cache 's3://bucket9?endpoint=http://localhost:59432®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/nix/var/nix/builds/nix-38446-2842733125/TestClientCADerivations740139489/001/store'990 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 1991--- PASS: TestClientCADerivations (1.87s)992=== CONT TestRedundantMultipartUpload9932026/09/21 13:24:24 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9942026/09/21 13:24:24 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst995--- PASS: TestCompleteMultipartUnregistered (1.29s)996=== CONT TestReadRedirectUsesPublicS3URL9972026/09/21 13:24:24 INFO Received uploads request method=POST path=/api/pending_closures9982026/09/21 13:24:24 INFO Received uploads request method=POST path=/api/pending_closures9992026/09/21 13:24:24 INFO Received uploads request method=POST path=/api/pending_closures10002026/09/21 13:24:24 INFO Received uploads request method=POST path=/api/pending_closures10012026/09/21 13:24:25 INFO Received cleanup request method=DELETE path=/api/pending_closures10022026/09/21 13:24:25 INFO Aborted multipart uploads count=010032026/09/21 13:24:25 INFO Received uploads request method=POST path=/api/pending_closures10042026/09/21 13:24:25 INFO Received cleanup request method=DELETE path=/api/pending_closures10052026/09/21 13:24:25 INFO Aborted multipart uploads count=110062026/09/21 13:24:25 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete10072026-09-21 13:24:25.112 UTC [38706] ERROR: Closure does not exist: id=110082026-09-21 13:24:25.112 UTC [38706] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 16 at RAISE10092026-09-21 13:24:25.112 UTC [38706] STATEMENT: -- name: CommitPendingClosure :exec1010 SELECT commit_pending_closure($1::bigint)1011 1012--- PASS: TestService_cleanupPendingClosuresHandler (1.51s)1013=== CONT TestService_ReadAuthMiddleware10142026/09/21 13:24:25 INFO Received uploads request method=POST path=/api/pending_closures10152026-09-21 13:24:25.310 UTC [38753] ERROR: relation "goose_db_version" does not exist at character 3610162026-09-21 13:24:25.310 UTC [38753] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10172026-09-21 13:24:25.493 UTC [38754] ERROR: relation "goose_db_version" does not exist at character 3610182026-09-21 13:24:25.493 UTC [38754] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10192026/09/21 13:24:25 OK 20241026095416_initial_model.sql (166.44ms)10202026/09/21 13:24:25 OK 20251210153512_drop_unused_gin_index.sql (7.09ms)10212026/09/21 13:24:25 OK 20251218171726_add_pins.sql (51.18ms)10222026-09-21 13:24:25.608 UTC [38758] ERROR: relation "goose_db_version" does not exist at character 3610232026-09-21 13:24:25.608 UTC [38758] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10242026/09/21 13:24:25 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10252026/09/21 13:24:25 OK 20260628120000_add_object_size_and_stats.sql (48.09ms)10262026/09/21 13:24:25 OK 20260905000000_add_claims.sql (32.46ms)10272026/09/21 13:24:25 OK 20260920000000_drop_claims.sql (10.03ms)10282026/09/21 13:24:25 goose: successfully migrated database to version: 2026092000000010292026/09/21 13:24:25 OK 20241026095416_initial_model.sql (134.02ms)10302026/09/21 13:24:25 OK 20251210153512_drop_unused_gin_index.sql (1.01ms)10312026/09/21 13:24:25 OK 1_commit_pending_closure.sql (2.22ms)10322026/09/21 13:24:25 OK 2_object_stats_trigger.sql (588.58µs)10332026/09/21 13:24:25 goose: up to current file version: 210342026/09/21 13:24:25 OK 20251218171726_add_pins.sql (1.6ms)10352026/09/21 13:24:25 OK 20260628120000_add_object_size_and_stats.sql (40.73ms)10362026-09-21 13:24:25.775 UTC [38760] ERROR: relation "goose_db_version" does not exist at character 3610372026-09-21 13:24:25.775 UTC [38760] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10382026/09/21 13:24:25 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10392026/09/21 13:24:25 OK 20260905000000_add_claims.sql (85.05ms)10402026/09/21 13:24:25 OK 20260920000000_drop_claims.sql (13.13ms)10412026/09/21 13:24:25 goose: successfully migrated database to version: 2026092000000010422026/09/21 13:24:25 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=Y2Y1OWE1YjctZGU2Ny00MDg3LTkxM2ItMTU1YmM1NjA0MWZhLjkzOTYwYzNlLTIxYzUtNDY3NC05NzZjLWQ2N2I1MjcyYjg2ZXgxNzg5OTk3MDY0NjE2MjEyMDAw parts=1010432026/09/21 13:24:25 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete10442026/09/21 13:24:25 OK 20241026095416_initial_model.sql (161.55ms)10452026/09/21 13:24:25 OK 20251210153512_drop_unused_gin_index.sql (3.21ms)10462026/09/21 13:24:25 OK 1_commit_pending_closure.sql (5.09ms)10472026/09/21 13:24:25 OK 2_object_stats_trigger.sql (663.83µs)10482026/09/21 13:24:25 goose: up to current file version: 210492026/09/21 13:24:25 INFO Completed upload id=110502026/09/21 13:24:25 INFO Received uploads request method=POST path=/api/pending_closures10512026/09/21 13:24:25 INFO Received uploads request method=POST path=/api/pending_closures10522026/09/21 13:24:25 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo10532026/09/21 13:24:25 WARN Found objects in DB but missing from S3, will re-upload count=11054--- PASS: TestService_verifyS3Integrity (2.55s)1055=== CONT TestService_AuthMiddleware_OIDC10562026/09/21 13:24:25 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:59480/oidc10572026/09/21 13:24:25 OK 20251218171726_add_pins.sql (23.35ms)10582026/09/21 13:24:25 OK 20260628120000_add_object_size_and_stats.sql (42.12ms)10592026/09/21 13:24:25 OK 20260905000000_add_claims.sql (47.2ms)10602026/09/21 13:24:25 OK 20241026095416_initial_model.sql (142.72ms)10612026/09/21 13:24:25 OK 20260920000000_drop_claims.sql (28.74ms)10622026/09/21 13:24:25 goose: successfully migrated database to version: 202609200000001063--- PASS: TestService_Rustfstest (1.87s)1064=== CONT TestReadProxyNarStreaming10652026/09/21 13:24:25 OK 20251210153512_drop_unused_gin_index.sql (3.89ms)10662026/09/21 13:24:25 OK 1_commit_pending_closure.sql (3.8ms)10672026/09/21 13:24:25 OK 2_object_stats_trigger.sql (2.02ms)10682026/09/21 13:24:25 goose: up to current file version: 210692026/09/21 13:24:26 OK 20251218171726_add_pins.sql (27.06ms)10702026/09/21 13:24:26 OK 20260628120000_add_object_size_and_stats.sql (28.27ms)10712026-09-21 13:24:26.047 UTC [38770] ERROR: relation "goose_db_version" does not exist at character 3610722026-09-21 13:24:26.047 UTC [38770] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10732026/09/21 13:24:26 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10742026/09/21 13:24:26 OK 20260905000000_add_claims.sql (50.47ms)10752026-09-21 13:24:26.090 UTC [38771] ERROR: relation "goose_db_version" does not exist at character 3610762026-09-21 13:24:26.090 UTC [38771] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10772026/09/21 13:24:26 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=Y2Y1OWE1YjctZGU2Ny00MDg3LTkxM2ItMTU1YmM1NjA0MWZhLjBiOGFlZGExLTVjYWQtNGI2YS04MzcwLWY3ZWQ2MWM0ZWU1MXgxNzg5OTk3MDY0Nzg0MTkyMDAw parts=1010782026/09/21 13:24:26 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete10792026/09/21 13:24:26 INFO Completed upload id=110802026/09/21 13:24:26 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000010812026/09/21 13:24:26 OK 20260920000000_drop_claims.sql (10.83ms)10822026/09/21 13:24:26 goose: successfully migrated database to version: 2026092000000010832026/09/21 13:24:26 INFO Received uploads request method=POST path=/api/pending_closures10842026/09/21 13:24:26 INFO Starting cleanup of old closures method=DELETE path=/api/closures10852026/09/21 13:24:26 OK 1_commit_pending_closure.sql (1.65ms)10862026/09/21 13:24:26 OK 2_object_stats_trigger.sql (376.46µs)10872026/09/21 13:24:26 goose: up to current file version: 210882026/09/21 13:24:26 INFO Aborted multipart uploads count=010892026/09/21 13:24:26 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=010902026/09/21 13:24:26 INFO Vacuumed table table=pending_closures10912026/09/21 13:24:26 INFO Vacuumed table table=pending_objects10922026/09/21 13:24:26 INFO Vacuumed table table=multipart_uploads10932026/09/21 13:24:26 INFO Vacuumed table table=closures10942026/09/21 13:24:26 INFO Vacuumed table table=objects10952026/09/21 13:24:26 OK 20241026095416_initial_model.sql (83.56ms)10962026/09/21 13:24:26 OK 20251210153512_drop_unused_gin_index.sql (14.72ms)10972026/09/21 13:24:26 INFO Received uploads request method=POST path=/api/pending_closures10982026/09/21 13:24:26 OK 20251218171726_add_pins.sql (6.57ms)10992026/09/21 13:24:26 OK 20241026095416_initial_model.sql (72.33ms)11002026/09/21 13:24:26 OK 20251210153512_drop_unused_gin_index.sql (1.77ms)11012026/09/21 13:24:26 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001102--- PASS: TestService_createPendingClosureHandler (2.76s)1103=== CONT TestReadRedirectKeepsNarinfoProxied11042026/09/21 13:24:26 OK 20260628120000_add_object_size_and_stats.sql (16.4ms)11052026/09/21 13:24:26 OK 20251218171726_add_pins.sql (20.34ms)11062026/09/21 13:24:26 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst11072026/09/21 13:24:26 INFO Received uploads request method=POST path=/api/pending_closures1108--- PASS: TestPresignedUploadRegisteredBeforeCommit (2.02s)1109=== CONT TestReadRedirectNar11102026/09/21 13:24:26 OK 20260905000000_add_claims.sql (18.15ms)11112026/09/21 13:24:26 OK 20260628120000_add_object_size_and_stats.sql (10.67ms)11122026/09/21 13:24:26 OK 20260920000000_drop_claims.sql (8.86ms)11132026/09/21 13:24:26 goose: successfully migrated database to version: 2026092000000011142026/09/21 13:24:26 OK 1_commit_pending_closure.sql (1.31ms)11152026/09/21 13:24:26 OK 2_object_stats_trigger.sql (299.5µs)11162026/09/21 13:24:26 goose: up to current file version: 211172026/09/21 13:24:26 OK 20260905000000_add_claims.sql (15.77ms)11182026/09/21 13:24:26 OK 20260920000000_drop_claims.sql (8.58ms)11192026/09/21 13:24:26 goose: successfully migrated database to version: 2026092000000011202026/09/21 13:24:26 OK 1_commit_pending_closure.sql (875.67µs)11212026/09/21 13:24:26 OK 2_object_stats_trigger.sql (212.21µs)11222026/09/21 13:24:26 goose: up to current file version: 211232026/09/21 13:24:26 INFO Received uploads request method=POST path=/api/pending_closures11242026-09-21 13:24:26.346 UTC [38779] ERROR: relation "goose_db_version" does not exist at character 3611252026-09-21 13:24:26.346 UTC [38779] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11262026/09/21 13:24:26 OK 20241026095416_initial_model.sql (36.93ms)11272026/09/21 13:24:26 OK 20251210153512_drop_unused_gin_index.sql (8.39ms)11282026/09/21 13:24:26 OK 20251218171726_add_pins.sql (24.18ms)11292026/09/21 13:24:26 OK 20260628120000_add_object_size_and_stats.sql (29.18ms)11302026/09/21 13:24:26 OK 20260905000000_add_claims.sql (30.42ms)11312026/09/21 13:24:26 INFO Received uploads request method=POST path=/api/pending_closures11322026/09/21 13:24:26 OK 20260920000000_drop_claims.sql (18.3ms)11332026/09/21 13:24:26 goose: successfully migrated database to version: 2026092000000011342026/09/21 13:24:26 OK 1_commit_pending_closure.sql (1.17ms)11352026/09/21 13:24:26 OK 2_object_stats_trigger.sql (239.13µs)11362026/09/21 13:24:26 goose: up to current file version: 211372026/09/21 13:24:26 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11382026/09/21 13:24:26 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=Y2Y1OWE1YjctZGU2Ny00MDg3LTkxM2ItMTU1YmM1NjA0MWZhLjU1OGEwZjliLTVjZGEtNDBkYy1hMDkzLWVlNTAwOGRiNDQyNXgxNzg5OTk3MDY2NTM5MTg5MDAw11392026/09/21 13:24:26 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=Y2Y1OWE1YjctZGU2Ny00MDg3LTkxM2ItMTU1YmM1NjA0MWZhLjU1OGEwZjliLTVjZGEtNDBkYy1hMDkzLWVlNTAwOGRiNDQyNXgxNzg5OTk3MDY2NTM5MTg5MDAw parts=11140--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (2.35s)1141=== CONT TestReadProxyDisabled11422026/09/21 13:24:26 INFO Received uploads request method=POST path=/api/pending_closures11432026/09/21 13:24:26 INFO Received uploads request method=POST path=/api/pending_closures1144--- PASS: TestReadRedirectUsesPublicS3URL (2.57s)1145=== CONT TestReadProxyRootRedirectsToIndexHTML11462026-09-21 13:24:27.228 UTC [38792] ERROR: relation "goose_db_version" does not exist at character 3611472026-09-21 13:24:27.228 UTC [38792] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1148--- PASS: TestService_ReadAuthMiddleware (2.19s)1149=== CONT TestReadProxyConditionalGet11502026-09-21 13:24:27.379 UTC [38795] ERROR: relation "goose_db_version" does not exist at character 3611512026-09-21 13:24:27.379 UTC [38795] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11522026/09/21 13:24:27 OK 20241026095416_initial_model.sql (115.22ms)11532026/09/21 13:24:27 OK 20251210153512_drop_unused_gin_index.sql (1.72ms)11542026/09/21 13:24:27 OK 20251218171726_add_pins.sql (14.04ms)11552026/09/21 13:24:27 OK 20260628120000_add_object_size_and_stats.sql (39.12ms)11562026/09/21 13:24:27 OK 20260905000000_add_claims.sql (34.7ms)11572026/09/21 13:24:27 OK 20241026095416_initial_model.sql (103.3ms)11582026/09/21 13:24:27 OK 20251210153512_drop_unused_gin_index.sql (1.12ms)11592026/09/21 13:24:27 OK 20260920000000_drop_claims.sql (17.46ms)11602026/09/21 13:24:27 goose: successfully migrated database to version: 2026092000000011612026/09/21 13:24:27 OK 1_commit_pending_closure.sql (1.01ms)11622026/09/21 13:24:27 OK 2_object_stats_trigger.sql (253.33µs)11632026/09/21 13:24:27 goose: up to current file version: 211642026-09-21 13:24:27.542 UTC [38798] ERROR: relation "goose_db_version" does not exist at character 3611652026-09-21 13:24:27.542 UTC [38798] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11662026/09/21 13:24:27 OK 20251218171726_add_pins.sql (80.19ms)11672026/09/21 13:24:27 OK 20260628120000_add_object_size_and_stats.sql (36.59ms)11682026/09/21 13:24:27 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11692026-09-21 13:24:27.720 UTC [38799] ERROR: relation "goose_db_version" does not exist at character 3611702026-09-21 13:24:27.720 UTC [38799] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11712026/09/21 13:24:27 OK 20260905000000_add_claims.sql (92.71ms)11722026/09/21 13:24:27 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=Y2Y1OWE1YjctZGU2Ny00MDg3LTkxM2ItMTU1YmM1NjA0MWZhLjFkMTVmY2QyLTU5MzYtNDkzMi1hMzkyLTA4MjgyNzkyN2IxY3gxNzg5OTk3MDY2MzYwNjUxMDAw parts=1211732026/09/21 13:24:27 INFO Received uploads request method=POST path=/api/pending_closures1174--- PASS: TestCompletedNarNotReofferedAcrossClosures (3.52s)1175=== CONT TestReadProxyHead11762026/09/21 13:24:27 OK 20260920000000_drop_claims.sql (25.68ms)11772026/09/21 13:24:27 goose: successfully migrated database to version: 2026092000000011782026/09/21 13:24:27 OK 1_commit_pending_closure.sql (1.29ms)11792026/09/21 13:24:27 OK 2_object_stats_trigger.sql (592.96µs)11802026/09/21 13:24:27 goose: up to current file version: 21181=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1182=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1183=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1184=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1185=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1186=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1187=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1188=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1189=== CONT TestReadProxyInvalidPath11902026/09/21 13:24:27 OK 20241026095416_initial_model.sql (206.31ms)11912026/09/21 13:24:27 OK 20251210153512_drop_unused_gin_index.sql (13.1ms)11922026/09/21 13:24:27 OK 20251218171726_add_pins.sql (10.11ms)11932026/09/21 13:24:27 OK 20260628120000_add_object_size_and_stats.sql (21.87ms)11942026/09/21 13:24:27 OK 20241026095416_initial_model.sql (100.83ms)11952026/09/21 13:24:27 OK 20251210153512_drop_unused_gin_index.sql (6.89ms)11962026/09/21 13:24:27 OK 20251218171726_add_pins.sql (25.72ms)11972026/09/21 13:24:27 OK 20260905000000_add_claims.sql (49.32ms)11982026/09/21 13:24:27 OK 20260628120000_add_object_size_and_stats.sql (43.6ms)11992026/09/21 13:24:27 OK 20260920000000_drop_claims.sql (27.32ms)12002026/09/21 13:24:27 goose: successfully migrated database to version: 2026092000000012012026/09/21 13:24:27 OK 1_commit_pending_closure.sql (1.39ms)12022026/09/21 13:24:27 OK 2_object_stats_trigger.sql (230.04µs)12032026/09/21 13:24:27 goose: up to current file version: 212042026/09/21 13:24:27 OK 20260905000000_add_claims.sql (24.93ms)12052026/09/21 13:24:27 OK 20260920000000_drop_claims.sql (21.31ms)12062026/09/21 13:24:27 goose: successfully migrated database to version: 2026092000000012072026/09/21 13:24:27 OK 1_commit_pending_closure.sql (1.2ms)12082026/09/21 13:24:27 OK 2_object_stats_trigger.sql (250.04µs)12092026/09/21 13:24:27 goose: up to current file version: 21210--- PASS: TestReadProxyNarStreaming (2.03s)1211=== CONT TestReadProxy40412122026/09/21 13:24:28 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12132026/09/21 13:24:28 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=Y2Y1OWE1YjctZGU2Ny00MDg3LTkxM2ItMTU1YmM1NjA0MWZhLmIzM2E5NTg4LTdkZTItNGJhNS04ZGIyLTEyNmI0MzAzYTg2ZngxNzg5OTk3MDY2NzYyNjQ3MDAw parts=121214--- PASS: TestRedundantMultipartUpload (3.76s)1215=== CONT TestClientWithDependencies1216--- PASS: TestReadRedirectNar (2.08s)1217=== CONT TestResolveDBConnectionString1218=== RUN TestResolveDBConnectionString/flag_wins1219=== PAUSE TestResolveDBConnectionString/flag_wins1220=== RUN TestResolveDBConnectionString/file_when_flag_empty1221=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1222=== RUN TestResolveDBConnectionString/missing_file_is_an_error1223=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1224=== RUN TestResolveDBConnectionString/PGHOST_allows_empty1225=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1226=== RUN TestResolveDBConnectionString/nothing_configured1227=== PAUSE TestResolveDBConnectionString/nothing_configured1228=== CONT TestPinProtectsFromGC12292026-09-21 13:24:28.364 UTC [38810] ERROR: relation "goose_db_version" does not exist at character 3612302026-09-21 13:24:28.364 UTC [38810] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1231--- PASS: TestReadRedirectKeepsNarinfoProxied (2.30s)1232=== CONT TestClientSharedPathCommittedMidPush12332026/09/21 13:24:28 OK 20241026095416_initial_model.sql (158.37ms)12342026/09/21 13:24:28 OK 20251210153512_drop_unused_gin_index.sql (501.38µs)12352026/09/21 13:24:28 OK 20251218171726_add_pins.sql (1.29ms)12362026-09-21 13:24:28.559 UTC [38813] ERROR: relation "goose_db_version" does not exist at character 3612372026-09-21 13:24:28.559 UTC [38813] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12382026-09-21 13:24:28.562 UTC [38814] ERROR: relation "goose_db_version" does not exist at character 3612392026-09-21 13:24:28.562 UTC [38814] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12402026/09/21 13:24:28 OK 20260628120000_add_object_size_and_stats.sql (12.46ms)12412026/09/21 13:24:28 OK 20260905000000_add_claims.sql (3.11ms)12422026/09/21 13:24:28 OK 20260920000000_drop_claims.sql (1.28ms)12432026/09/21 13:24:28 goose: successfully migrated database to version: 2026092000000012442026/09/21 13:24:28 OK 1_commit_pending_closure.sql (1.48ms)12452026/09/21 13:24:28 OK 2_object_stats_trigger.sql (396.17µs)12462026/09/21 13:24:28 goose: up to current file version: 212472026/09/21 13:24:28 OK 20241026095416_initial_model.sql (8.96ms)12482026/09/21 13:24:28 OK 20251210153512_drop_unused_gin_index.sql (7.26ms)12492026/09/21 13:24:28 OK 20241026095416_initial_model.sql (22.46ms)12502026/09/21 13:24:28 OK 20251210153512_drop_unused_gin_index.sql (7.44ms)12512026/09/21 13:24:28 OK 20251218171726_add_pins.sql (13.81ms)12522026/09/21 13:24:28 OK 20251218171726_add_pins.sql (8.46ms)12532026/09/21 13:24:28 OK 20260628120000_add_object_size_and_stats.sql (15.06ms)12542026/09/21 13:24:28 OK 20260628120000_add_object_size_and_stats.sql (8.09ms)12552026/09/21 13:24:28 OK 20260905000000_add_claims.sql (13.41ms)12562026/09/21 13:24:28 OK 20260905000000_add_claims.sql (21.71ms)12572026/09/21 13:24:28 OK 20260920000000_drop_claims.sql (30.3ms)12582026/09/21 13:24:28 goose: successfully migrated database to version: 2026092000000012592026/09/21 13:24:28 OK 1_commit_pending_closure.sql (919.83µs)12602026/09/21 13:24:28 OK 2_object_stats_trigger.sql (218.38µs)12612026/09/21 13:24:28 goose: up to current file version: 212622026/09/21 13:24:28 OK 20260920000000_drop_claims.sql (35.72ms)12632026/09/21 13:24:28 goose: successfully migrated database to version: 2026092000000012642026/09/21 13:24:28 OK 1_commit_pending_closure.sql (1.2ms)12652026/09/21 13:24:28 OK 2_object_stats_trigger.sql (192µs)12662026/09/21 13:24:28 goose: up to current file version: 21267--- PASS: TestReadProxyDisabled (2.03s)1268=== CONT TestResurrectedObjectNotDeleted1269--- PASS: TestReadProxyConditionalGet (1.73s)1270=== CONT TestReadProxyNarinfoAlreadyDecompressed12712026-09-21 13:24:29.289 UTC [38821] ERROR: relation "goose_db_version" does not exist at character 3612722026-09-21 13:24:29.289 UTC [38821] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1273--- PASS: TestReadProxyRootRedirectsToIndexHTML (2.25s)1274=== CONT TestReadProxyNarinfo12752026-09-21 13:24:29.335 UTC [38822] ERROR: relation "goose_db_version" does not exist at character 3612762026-09-21 13:24:29.335 UTC [38822] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12772026-09-21 13:24:29.471 UTC [38826] ERROR: relation "goose_db_version" does not exist at character 3612782026-09-21 13:24:29.471 UTC [38826] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12792026/09/21 13:24:29 OK 20241026095416_initial_model.sql (136.51ms)12802026/09/21 13:24:29 OK 20251210153512_drop_unused_gin_index.sql (7.39ms)12812026/09/21 13:24:29 OK 20251218171726_add_pins.sql (27.13ms)12822026/09/21 13:24:29 OK 20241026095416_initial_model.sql (114.87ms)12832026/09/21 13:24:29 OK 20251210153512_drop_unused_gin_index.sql (1.36ms)12842026/09/21 13:24:29 OK 20251218171726_add_pins.sql (3.49ms)12852026-09-21 13:24:29.514 UTC [38828] ERROR: relation "goose_db_version" does not exist at character 3612862026-09-21 13:24:29.514 UTC [38828] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12872026/09/21 13:24:29 OK 20260628120000_add_object_size_and_stats.sql (7.75ms)12882026/09/21 13:24:29 OK 20260905000000_add_claims.sql (2.21ms)12892026/09/21 13:24:29 OK 20260920000000_drop_claims.sql (1.23ms)12902026/09/21 13:24:29 goose: successfully migrated database to version: 2026092000000012912026/09/21 13:24:29 OK 1_commit_pending_closure.sql (1.5ms)12922026/09/21 13:24:29 OK 20241026095416_initial_model.sql (13.24ms)12932026/09/21 13:24:29 OK 2_object_stats_trigger.sql (347.58µs)12942026/09/21 13:24:29 goose: up to current file version: 212952026/09/21 13:24:29 OK 20251210153512_drop_unused_gin_index.sql (691.92µs)12962026/09/21 13:24:29 OK 20260628120000_add_object_size_and_stats.sql (9.03ms)12972026/09/21 13:24:29 OK 20251218171726_add_pins.sql (1.61ms)12982026-09-21 13:24:29.523 UTC [38829] ERROR: relation "goose_db_version" does not exist at character 3612992026-09-21 13:24:29.523 UTC [38829] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13002026/09/21 13:24:29 OK 20260905000000_add_claims.sql (12.74ms)13012026/09/21 13:24:29 OK 20260920000000_drop_claims.sql (14.86ms)13022026/09/21 13:24:29 goose: successfully migrated database to version: 2026092000000013032026/09/21 13:24:29 OK 20260628120000_add_object_size_and_stats.sql (26.91ms)13042026/09/21 13:24:29 OK 1_commit_pending_closure.sql (1.74ms)13052026/09/21 13:24:29 OK 2_object_stats_trigger.sql (359.5µs)13062026/09/21 13:24:29 goose: up to current file version: 213072026/09/21 13:24:29 OK 20260905000000_add_claims.sql (57.78ms)13082026/09/21 13:24:29 OK 20260920000000_drop_claims.sql (37.57ms)13092026/09/21 13:24:29 goose: successfully migrated database to version: 2026092000000013102026/09/21 13:24:29 OK 1_commit_pending_closure.sql (3.53ms)13112026/09/21 13:24:29 OK 2_object_stats_trigger.sql (763.54µs)13122026/09/21 13:24:29 goose: up to current file version: 213132026/09/21 13:24:29 OK 20241026095416_initial_model.sql (176.08ms)13142026/09/21 13:24:29 OK 20251210153512_drop_unused_gin_index.sql (9.49ms)13152026/09/21 13:24:29 OK 20241026095416_initial_model.sql (169.95ms)13162026/09/21 13:24:29 OK 20251218171726_add_pins.sql (21.34ms)13172026/09/21 13:24:29 OK 20251210153512_drop_unused_gin_index.sql (13.99ms)13182026/09/21 13:24:29 OK 20260628120000_add_object_size_and_stats.sql (29.09ms)13192026/09/21 13:24:29 OK 20251218171726_add_pins.sql (23.78ms)1320--- PASS: TestReadProxyHead (2.05s)1321=== CONT TestIsValidCachePath1322=== RUN TestIsValidCachePath/narinfo1323=== PAUSE TestIsValidCachePath/narinfo1324=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars1325=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars1326=== RUN TestIsValidCachePath/nar_zst1327=== PAUSE TestIsValidCachePath/nar_zst1328=== RUN TestIsValidCachePath/nar_xz1329=== PAUSE TestIsValidCachePath/nar_xz1330=== RUN TestIsValidCachePath/nar_bz21331=== PAUSE TestIsValidCachePath/nar_bz21332=== RUN TestIsValidCachePath/nar_uncompressed1333=== PAUSE TestIsValidCachePath/nar_uncompressed1334=== RUN TestIsValidCachePath/ls1335=== PAUSE TestIsValidCachePath/ls1336=== RUN TestIsValidCachePath/log1337=== PAUSE TestIsValidCachePath/log1338=== RUN TestIsValidCachePath/realisation1339=== PAUSE TestIsValidCachePath/realisation1340=== RUN TestIsValidCachePath/nix-cache-info1341=== PAUSE TestIsValidCachePath/nix-cache-info1342=== RUN TestIsValidCachePath/index.html1343=== PAUSE TestIsValidCachePath/index.html1344=== RUN TestIsValidCachePath/traversal_parent1345=== PAUSE TestIsValidCachePath/traversal_parent1346=== RUN TestIsValidCachePath/traversal_in_middle1347=== PAUSE TestIsValidCachePath/traversal_in_middle1348=== RUN TestIsValidCachePath/invalid_char_e1349=== PAUSE TestIsValidCachePath/invalid_char_e1350=== RUN TestIsValidCachePath/invalid_char_u1351=== PAUSE TestIsValidCachePath/invalid_char_u1352=== RUN TestIsValidCachePath/random_path1353=== PAUSE TestIsValidCachePath/random_path1354=== RUN TestIsValidCachePath/empty1355=== PAUSE TestIsValidCachePath/empty1356=== RUN TestIsValidCachePath/leading_slash1357=== PAUSE TestIsValidCachePath/leading_slash1358=== RUN TestIsValidCachePath/wrong_extension1359=== PAUSE TestIsValidCachePath/wrong_extension1360=== RUN TestIsValidCachePath/short_hash1361=== PAUSE TestIsValidCachePath/short_hash1362=== CONT TestParseSingleRange1363=== RUN TestParseSingleRange/none1364=== PAUSE TestParseSingleRange/none1365=== RUN TestParseSingleRange/unknown_unit1366=== PAUSE TestParseSingleRange/unknown_unit1367=== RUN TestParseSingleRange/multi-range_ignored1368=== PAUSE TestParseSingleRange/multi-range_ignored1369=== RUN TestParseSingleRange/malformed_no_dash1370=== PAUSE TestParseSingleRange/malformed_no_dash1371=== RUN TestParseSingleRange/malformed_both_empty1372=== PAUSE TestParseSingleRange/malformed_both_empty1373=== RUN TestParseSingleRange/malformed_end_before_start1374=== PAUSE TestParseSingleRange/malformed_end_before_start1375=== RUN TestParseSingleRange/closed1376=== PAUSE TestParseSingleRange/closed1377=== RUN TestParseSingleRange/open-ended1378=== PAUSE TestParseSingleRange/open-ended1379=== RUN TestParseSingleRange/end_clamped_to_size1380=== PAUSE TestParseSingleRange/end_clamped_to_size1381=== RUN TestParseSingleRange/suffix1382=== PAUSE TestParseSingleRange/suffix1383=== RUN TestParseSingleRange/suffix_exceeds_size1384=== PAUSE TestParseSingleRange/suffix_exceeds_size1385=== RUN TestParseSingleRange/single_byte1386=== PAUSE TestParseSingleRange/single_byte1387=== RUN TestParseSingleRange/start_past_EOF1388=== PAUSE TestParseSingleRange/start_past_EOF1389=== RUN TestParseSingleRange/start_far_past_EOF1390=== PAUSE TestParseSingleRange/start_far_past_EOF1391=== CONT TestObjectStatsTrigger13922026/09/21 13:24:29 OK 20260628120000_add_object_size_and_stats.sql (37.77ms)13932026/09/21 13:24:29 OK 20260905000000_add_claims.sql (78.38ms)13942026/09/21 13:24:29 OK 20260905000000_add_claims.sql (44.58ms)13952026/09/21 13:24:29 OK 20260920000000_drop_claims.sql (38.18ms)13962026/09/21 13:24:29 goose: successfully migrated database to version: 2026092000000013972026/09/21 13:24:29 OK 20260920000000_drop_claims.sql (33.31ms)13982026/09/21 13:24:29 goose: successfully migrated database to version: 2026092000000013992026/09/21 13:24:29 OK 1_commit_pending_closure.sql (3.54ms)14002026/09/21 13:24:29 OK 1_commit_pending_closure.sql (3.54ms)14012026/09/21 13:24:29 OK 2_object_stats_trigger.sql (731.63µs)14022026/09/21 13:24:29 goose: up to current file version: 214032026/09/21 13:24:29 OK 2_object_stats_trigger.sql (967.96µs)14042026/09/21 13:24:29 goose: up to current file version: 21405--- PASS: TestReadProxyInvalidPath (2.23s)1406=== CONT TestOrphanedObjectsGCStressTest14072026/09/21 13:24:30 WARN Rate limiter enabled after throttle name=s3-test rate=514082026/09/21 13:24:30 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."1409=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle1410 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=101411 throttle_test.go:215: Rate limiter: enabled=true, rate=5.001412--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (6.29s)1413=== CONT TestOrphanedObjectsGC14142026-09-21 13:24:30.231 UTC [38836] ERROR: relation "goose_db_version" does not exist at character 3614152026-09-21 13:24:30.231 UTC [38836] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1416--- PASS: TestReadProxy404 (2.25s)1417=== CONT TestService_AuthMiddleware_MTLSBoundSubjects14182026/09/21 13:24:30 OK 20241026095416_initial_model.sql (105.13ms)14192026/09/21 13:24:30 OK 20251210153512_drop_unused_gin_index.sql (5.3ms)14202026/09/21 13:24:30 OK 20251218171726_add_pins.sql (40.07ms)14212026/09/21 13:24:30 OK 20260628120000_add_object_size_and_stats.sql (38.02ms)14222026/09/21 13:24:30 OK 20260905000000_add_claims.sql (62.93ms)14232026/09/21 13:24:30 OK 20260920000000_drop_claims.sql (41.44ms)14242026/09/21 13:24:30 goose: successfully migrated database to version: 2026092000000014252026/09/21 13:24:30 OK 1_commit_pending_closure.sql (5.72ms)14262026/09/21 13:24:30 OK 2_object_stats_trigger.sql (882.63µs)14272026/09/21 13:24:30 goose: up to current file version: 214282026-09-21 13:24:30.639 UTC [38839] ERROR: relation "goose_db_version" does not exist at character 3614292026-09-21 13:24:30.639 UTC [38839] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14302026/09/21 13:24:30 OK 20241026095416_initial_model.sql (166.84ms)14312026/09/21 13:24:30 OK 20251210153512_drop_unused_gin_index.sql (15.47ms)14322026/09/21 13:24:30 OK 20251218171726_add_pins.sql (36.57ms)14332026-09-21 13:24:30.926 UTC [38843] ERROR: relation "goose_db_version" does not exist at character 3614342026-09-21 13:24:30.926 UTC [38843] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1435=== NAME TestPinProtectsFromGC1436 client_integration_test.go:731: Pinned store path: /nix/var/nix/builds/nix-38446-2842733125/TestPinProtectsFromGC379389027/001/store/pdxgr7gcf1rld0z9r8rxww1lsndp55x4-pinned-file.txt1437 client_integration_test.go:732: Unpinned store path: /nix/var/nix/builds/nix-38446-2842733125/TestPinProtectsFromGC379389027/001/store/09b4malc93v7z1k23fdfhsl6wm0qz0kp-unpinned-file.txt14382026/09/21 13:24:30 OK 20260628120000_add_object_size_and_stats.sql (33.34ms)14392026/09/21 13:24:30 OK 20260905000000_add_claims.sql (42.46ms)14402026/09/21 13:24:31 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"14412026/09/21 13:24:31 OK 20260920000000_drop_claims.sql (30.97ms)14422026/09/21 13:24:31 goose: successfully migrated database to version: 2026092000000014432026/09/21 13:24:31 OK 1_commit_pending_closure.sql (1.53ms)14442026/09/21 13:24:31 OK 2_object_stats_trigger.sql (238.29µs)14452026/09/21 13:24:31 goose: up to current file version: 214462026-09-21 13:24:31.059 UTC [38852] ERROR: relation "goose_db_version" does not exist at character 3614472026-09-21 13:24:31.059 UTC [38852] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14482026/09/21 13:24:31 INFO Received uploads request method=POST path=/api/pending_closures14492026/09/21 13:24:31 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)14502026/09/21 13:24:31 INFO Uploading pdxgr7gcf1rld0z9r8rxww1lsndp55x4-pinned-file.txt (128B)14512026/09/21 13:24:31 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"14522026/09/21 13:24:31 OK 20241026095416_initial_model.sql (139.01ms)14532026/09/21 13:24:31 OK 20251210153512_drop_unused_gin_index.sql (5.08ms)14542026/09/21 13:24:31 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign14552026/09/21 13:24:31 WARN Failed to register uploaded object key=pdxgr7gcf1rld0z9r8rxww1lsndp55x4.ls error="server returned 404: 404 page not found\n"14562026/09/21 13:24:31 INFO Signed narinfos id=1 count=114572026/09/21 13:24:31 INFO Uploading 1 narinfos14582026/09/21 13:24:31 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete14592026/09/21 13:24:31 WARN Failed to register uploaded object key=pdxgr7gcf1rld0z9r8rxww1lsndp55x4.narinfo error="server returned 404: 404 page not found\n"14602026/09/21 13:24:31 OK 20251218171726_add_pins.sql (15.27ms)14612026/09/21 13:24:31 INFO Completed upload id=114622026/09/21 13:24:31 INFO Upload complete. (171ms)14632026/09/21 13:24:31 OK 20260628120000_add_object_size_and_stats.sql (3.44ms)14642026/09/21 13:24:31 OK 20260905000000_add_claims.sql (34.06ms)14652026/09/21 13:24:31 OK 20241026095416_initial_model.sql (94.19ms)14662026/09/21 13:24:31 OK 20251210153512_drop_unused_gin_index.sql (1.34ms)14672026/09/21 13:24:31 OK 20260920000000_drop_claims.sql (35.24ms)14682026/09/21 13:24:31 goose: successfully migrated database to version: 2026092000000014692026/09/21 13:24:31 OK 20251218171726_add_pins.sql (18.93ms)14702026/09/21 13:24:31 OK 1_commit_pending_closure.sql (1.21ms)14712026/09/21 13:24:31 OK 2_object_stats_trigger.sql (405.75µs)14722026/09/21 13:24:31 goose: up to current file version: 214732026/09/21 13:24:31 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"14742026/09/21 13:24:31 OK 20260628120000_add_object_size_and_stats.sql (16.71ms)1475=== NAME TestClientWithDependencies1476 client_integration_test.go:613: Built derivation: /nix/var/nix/builds/nix-38446-2842733125/TestClientWithDependencies232142047/001/store/j46cmla3infjifa39fpb8gzmc52s17kp-test-script14772026/09/21 13:24:31 INFO Received uploads request method=POST path=/api/pending_closures14782026/09/21 13:24:31 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)14792026/09/21 13:24:31 INFO Uploading 09b4malc93v7z1k23fdfhsl6wm0qz0kp-unpinned-file.txt (128B)14802026/09/21 13:24:31 OK 20260905000000_add_claims.sql (33.14ms)14812026/09/21 13:24:31 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"14822026/09/21 13:24:31 OK 20260920000000_drop_claims.sql (10.2ms)14832026/09/21 13:24:31 goose: successfully migrated database to version: 2026092000000014842026/09/21 13:24:31 OK 1_commit_pending_closure.sql (1.09ms)14852026/09/21 13:24:31 OK 2_object_stats_trigger.sql (241.79µs)14862026/09/21 13:24:31 goose: up to current file version: 214872026/09/21 13:24:31 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign14882026/09/21 13:24:31 INFO Signed narinfos id=2 count=114892026/09/21 13:24:31 INFO Uploading 1 narinfos14902026/09/21 13:24:31 WARN Failed to register uploaded object key=09b4malc93v7z1k23fdfhsl6wm0qz0kp.ls error="server returned 404: 404 page not found\n"14912026/09/21 13:24:31 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete14922026/09/21 13:24:31 WARN Failed to register uploaded object key=09b4malc93v7z1k23fdfhsl6wm0qz0kp.narinfo error="server returned 404: 404 page not found\n"14932026/09/21 13:24:31 INFO Completed upload id=214942026/09/21 13:24:31 INFO Upload complete. (106ms)1495 client_integration_test.go:615: Found 1 dependencies (including self)14962026-09-21 13:24:31.308 UTC [38872] ERROR: relation "goose_db_version" does not exist at character 3614972026-09-21 13:24:31.308 UTC [38872] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14982026/09/21 13:24:31 INFO Received create pin request method=POST path=/api/pins/myapp14992026/09/21 13:24:31 INFO Created/updated pin name=myapp store_path=/nix/var/nix/builds/nix-38446-2842733125/TestPinProtectsFromGC379389027/001/store/pdxgr7gcf1rld0z9r8rxww1lsndp55x4-pinned-file.txt narinfo_key=pdxgr7gcf1rld0z9r8rxww1lsndp55x4.narinfo15002026/09/21 13:24:31 INFO Starting cleanup of old closures method=DELETE path=/api/closures15012026/09/21 13:24:31 INFO Garbage collection started15022026/09/21 13:24:31 INFO Aborted multipart uploads count=015032026/09/21 13:24:31 WARN Force mode enabled - objects will be deleted immediately without grace period15042026-09-21 13:24:31.337 UTC [38877] ERROR: relation "goose_db_version" does not exist at character 3615052026-09-21 13:24:31.337 UTC [38877] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1506--- PASS: TestResurrectedObjectNotDeleted (2.57s)1507=== CONT TestMultipartCleanup15082026/09/21 13:24:31 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"15092026/09/21 13:24:31 OK 20241026095416_initial_model.sql (50.92ms)15102026/09/21 13:24:31 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"15112026/09/21 13:24:31 INFO Received uploads request method=POST path=/api/pending_closures15122026/09/21 13:24:31 OK 20251210153512_drop_unused_gin_index.sql (9.16ms)15132026/09/21 13:24:31 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15142026/09/21 13:24:31 INFO Uploading j46cmla3infjifa39fpb8gzmc52s17kp-test-script (136B)15152026/09/21 13:24:31 OK 20251218171726_add_pins.sql (12.86ms)15162026/09/21 13:24:31 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"15172026/09/21 13:24:31 WARN Failed to register uploaded object key=log/4as6v21d951rarq2q0vgzf9wdjp3s7gk-test-script.drv error="server returned 404: 404 page not found\n"15182026/09/21 13:24:31 OK 20260628120000_add_object_size_and_stats.sql (14.27ms)15192026-09-21 13:24:31.413 UTC [38885] ERROR: relation "goose_db_version" does not exist at character 3615202026-09-21 13:24:31.413 UTC [38885] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15212026/09/21 13:24:31 OK 20241026095416_initial_model.sql (63.68ms)15222026/09/21 13:24:31 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign15232026/09/21 13:24:31 WARN Failed to register uploaded object key=j46cmla3infjifa39fpb8gzmc52s17kp.ls error="server returned 404: 404 page not found\n"15242026/09/21 13:24:31 INFO Signed narinfos id=1 count=115252026/09/21 13:24:31 INFO Uploading 1 narinfos15262026/09/21 13:24:31 OK 20251210153512_drop_unused_gin_index.sql (6.18ms)15272026/09/21 13:24:31 INFO Received uploads request method=POST path=/api/pending_closures15282026/09/21 13:24:31 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete15292026/09/21 13:24:31 WARN Failed to register uploaded object key=j46cmla3infjifa39fpb8gzmc52s17kp.narinfo error="server returned 404: 404 page not found\n"15302026/09/21 13:24:31 OK 20260905000000_add_claims.sql (15.22ms)15312026/09/21 13:24:31 OK 20251218171726_add_pins.sql (16.89ms)15322026/09/21 13:24:31 INFO Completed upload id=115332026/09/21 13:24:31 INFO Upload complete. (112ms)1534=== NAME TestClientWithDependencies1535 client_integration_test.go:617: Skipping nix copy test - isolated store (/nix/var/nix/builds/nix-38446-2842733125/TestClientWithDependencies232142047/001/store) requires matching store prefix15362026/09/21 13:24:31 OK 20260920000000_drop_claims.sql (15.9ms)15372026/09/21 13:24:31 goose: successfully migrated database to version: 2026092000000015382026-09-21 13:24:31.444 UTC [38887] ERROR: relation "goose_db_version" does not exist at character 3615392026-09-21 13:24:31.444 UTC [38887] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15402026/09/21 13:24:31 OK 1_commit_pending_closure.sql (1.31ms)15412026/09/21 13:24:31 OK 2_object_stats_trigger.sql (357.67µs)15422026/09/21 13:24:31 goose: up to current file version: 215432026/09/21 13:24:31 OK 20260628120000_add_object_size_and_stats.sql (13.76ms)15442026/09/21 13:24:31 OK 20260905000000_add_claims.sql (22.35ms)1545--- PASS: TestClientWithDependencies (3.25s)1546=== CONT TestClientIntegration15472026/09/21 13:24:31 OK 20260920000000_drop_claims.sql (8.78ms)15482026/09/21 13:24:31 goose: successfully migrated database to version: 2026092000000015492026/09/21 13:24:31 OK 20241026095416_initial_model.sql (44.49ms)15502026/09/21 13:24:31 OK 1_commit_pending_closure.sql (1.7ms)1551--- PASS: TestReadProxyNarinfoAlreadyDecompressed (2.46s)1552=== CONT TestClientMultipleUploads15532026/09/21 13:24:31 OK 2_object_stats_trigger.sql (497.46µs)15542026/09/21 13:24:31 goose: up to current file version: 215552026/09/21 13:24:31 OK 20251210153512_drop_unused_gin_index.sql (7.6ms)15562026/09/21 13:24:31 OK 20251218171726_add_pins.sql (6.96ms)15572026/09/21 13:24:31 OK 20241026095416_initial_model.sql (30.39ms)15582026/09/21 13:24:31 OK 20260628120000_add_object_size_and_stats.sql (11.95ms)15592026/09/21 13:24:31 OK 20251210153512_drop_unused_gin_index.sql (542.54µs)15602026/09/21 13:24:31 OK 20251218171726_add_pins.sql (13.9ms)15612026/09/21 13:24:31 OK 20260905000000_add_claims.sql (14.33ms)15622026/09/21 13:24:31 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"15632026/09/21 13:24:31 OK 20260920000000_drop_claims.sql (8.37ms)15642026/09/21 13:24:31 goose: successfully migrated database to version: 2026092000000015652026/09/21 13:24:31 OK 1_commit_pending_closure.sql (888.92µs)15662026/09/21 13:24:31 OK 2_object_stats_trigger.sql (222.63µs)15672026/09/21 13:24:31 goose: up to current file version: 215682026/09/21 13:24:31 OK 20260628120000_add_object_size_and_stats.sql (15.19ms)15692026/09/21 13:24:31 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=015702026/09/21 13:24:31 OK 20260905000000_add_claims.sql (11.4ms)15712026/09/21 13:24:31 INFO Vacuumed table table=pending_closures15722026/09/21 13:24:31 OK 20260920000000_drop_claims.sql (12.24ms)15732026/09/21 13:24:31 goose: successfully migrated database to version: 2026092000000015742026/09/21 13:24:31 INFO Vacuumed table table=pending_objects15752026/09/21 13:24:31 INFO Vacuumed table table=multipart_uploads15762026/09/21 13:24:31 INFO Received uploads request method=POST path=/api/pending_closures15772026/09/21 13:24:31 OK 1_commit_pending_closure.sql (1.74ms)15782026/09/21 13:24:31 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15792026/09/21 13:24:31 INFO Uploading pb07201yn5gvnbpyj9f0kxvffhn0qlw8-shared-dep (136B)15802026/09/21 13:24:31 OK 2_object_stats_trigger.sql (372.58µs)15812026/09/21 13:24:31 goose: up to current file version: 215822026/09/21 13:24:31 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"15832026/09/21 13:24:31 INFO Vacuumed table table=closures15842026/09/21 13:24:31 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign15852026/09/21 13:24:31 INFO Signed narinfos id=2 count=115862026/09/21 13:24:31 WARN Failed to register uploaded object key=pb07201yn5gvnbpyj9f0kxvffhn0qlw8.ls error="server returned 404: 404 page not found\n"15872026/09/21 13:24:31 INFO Uploading 1 narinfos15882026/09/21 13:24:31 INFO Vacuumed table table=objects15892026/09/21 13:24:31 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete15902026/09/21 13:24:31 WARN Failed to register uploaded object key=pb07201yn5gvnbpyj9f0kxvffhn0qlw8.narinfo error="server returned 404: 404 page not found\n"15912026/09/21 13:24:31 INFO Completed upload id=215922026/09/21 13:24:31 INFO Upload complete. (132ms)15932026/09/21 13:24:31 INFO Received uploads request method=POST path=/api/pending_closures15942026/09/21 13:24:31 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)15952026/09/21 13:24:31 INFO Uploading pb07201yn5gvnbpyj9f0kxvffhn0qlw8-shared-dep (136B)15962026/09/21 13:24:31 INFO Uploading 9qmmmnb477l7s557vpqh4ihi83zwq8q1-top (256B)15972026/09/21 13:24:31 WARN Failed to register uploaded object key=nar/1bwy3rb41vbklkllvnj1i5k7c2g1lrigsp0s8r36cmbcmzsdw9fk.nar.zst error="server returned 404: 404 page not found\n"15982026/09/21 13:24:31 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"15992026/09/21 13:24:31 WARN Failed to register uploaded object key=9qmmmnb477l7s557vpqh4ihi83zwq8q1.ls error="server returned 404: 404 page not found\n"1600--- PASS: TestReadProxyNarinfo (2.34s)1601=== CONT TestService_AuthMiddleware_MTLSProxyHeader16022026/09/21 13:24:31 INFO Received sign narinfos request method=POST path=/api/pending_closures/3/sign16032026/09/21 13:24:31 WARN Failed to register uploaded object key=pb07201yn5gvnbpyj9f0kxvffhn0qlw8.ls error="server returned 404: 404 page not found\n"16042026/09/21 13:24:31 INFO Signed narinfos id=3 count=116052026/09/21 13:24:31 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign16062026/09/21 13:24:31 INFO Signed narinfos id=1 count=116072026/09/21 13:24:31 INFO Uploading 2 narinfos16082026/09/21 13:24:31 WARN Failed to register uploaded object key=9qmmmnb477l7s557vpqh4ihi83zwq8q1.narinfo error="server returned 404: 404 page not found\n"16092026/09/21 13:24:31 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete16102026/09/21 13:24:31 WARN Failed to register uploaded object key=pb07201yn5gvnbpyj9f0kxvffhn0qlw8.narinfo error="server returned 404: 404 page not found\n"16112026/09/21 13:24:31 INFO Completed upload id=116122026/09/21 13:24:31 INFO Received complete upload request method=POST path=/api/pending_closures/3/complete16132026/09/21 13:24:31 INFO Completed upload id=316142026/09/21 13:24:31 INFO Upload complete. (332ms)1615=== NAME TestClientSharedPathCommittedMidPush1616 client_integration_test.go:680: Retrieved narinfo from S3:1617 StorePath: /nix/var/nix/builds/nix-38446-2842733125/TestClientSharedPathCommittedMidPush1159385725/001/store/pb07201yn5gvnbpyj9f0kxvffhn0qlw8-shared-dep1618 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1619 Compression: zstd1620 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821621 NarSize: 1361622 References: 1623 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1624 client_integration_test.go:680: Retrieved narinfo from S3:1625 StorePath: /nix/var/nix/builds/nix-38446-2842733125/TestClientSharedPathCommittedMidPush1159385725/001/store/9qmmmnb477l7s557vpqh4ihi83zwq8q1-top1626 URL: nar/1bwy3rb41vbklkllvnj1i5k7c2g1lrigsp0s8r36cmbcmzsdw9fk.nar.zst1627 Compression: zstd1628 NarHash: sha256:1bwy3rb41vbklkllvnj1i5k7c2g1lrigsp0s8r36cmbcmzsdw9fk1629 NarSize: 2561630 References: /nix/var/nix/builds/nix-38446-2842733125/TestClientSharedPathCommittedMidPush1159385725/001/store/pb07201yn5gvnbpyj9f0kxvffhn0qlw8-shared-dep1631 CA: text:sha256:0h47b1qq281p7gm689knlrvx9cfd9lwg0wghp2c4xd3ara46lmzx1632--- PASS: TestClientSharedPathCommittedMidPush (3.16s)1633=== CONT TestClientErrorHandling1634=== RUN TestClientErrorHandling/InvalidStorePath1635=== PAUSE TestClientErrorHandling/InvalidStorePath1636=== RUN TestClientErrorHandling/InvalidAuthToken1637=== PAUSE TestClientErrorHandling/InvalidAuthToken1638=== RUN TestClientErrorHandling/ServerNotAvailable1639=== PAUSE TestClientErrorHandling/ServerNotAvailable1640=== CONT TestGCTaskStore_PhaseUpdates1641--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)1642=== CONT TestNARDeduplicationMetadataUploadBug1643--- PASS: TestObjectStatsTrigger (1.97s)1644=== CONT TestCreatePendingClosureRejectsOversizedNAR16452026/09/21 13:24:31 INFO Received uploads request method=POST path=/api/pending_closures1646--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)1647=== CONT TestCacheConfigHandlerMaxNarSize1648--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)1649=== CONT TestGenerateLandingPage1650--- PASS: TestGenerateLandingPage (0.00s)1651=== CONT TestService_readinessHandler16522026-09-21 13:24:31.984 UTC [38906] ERROR: relation "goose_db_version" does not exist at character 3616532026-09-21 13:24:31.984 UTC [38906] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16542026/09/21 13:24:32 OK 20241026095416_initial_model.sql (68.5ms)16552026/09/21 13:24:32 OK 20251210153512_drop_unused_gin_index.sql (8.7ms)16562026/09/21 13:24:32 OK 20251218171726_add_pins.sql (4.46ms)16572026/09/21 13:24:32 OK 20260628120000_add_object_size_and_stats.sql (27.97ms)16582026/09/21 13:24:32 OK 20260905000000_add_claims.sql (15.1ms)16592026/09/21 13:24:32 OK 20260920000000_drop_claims.sql (16.57ms)16602026/09/21 13:24:32 goose: successfully migrated database to version: 2026092000000016612026/09/21 13:24:32 OK 1_commit_pending_closure.sql (4.17ms)16622026/09/21 13:24:32 OK 2_object_stats_trigger.sql (870.58µs)16632026/09/21 13:24:32 goose: up to current file version: 216642026/09/21 13:24:32 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"16652026/09/21 13:24:32 WARN mTLS auth: bound subjects configured but subject DN unavailable16662026/09/21 13:24:32 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1667--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (2.02s)1668=== CONT TestService_healthCheckHandler16692026-09-21 13:24:32.300 UTC [38908] ERROR: relation "goose_db_version" does not exist at character 3616702026-09-21 13:24:32.300 UTC [38908] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16712026-09-21 13:24:32.308 UTC [38909] ERROR: relation "goose_db_version" does not exist at character 3616722026-09-21 13:24:32.308 UTC [38909] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16732026/09/21 13:24:32 OK 20241026095416_initial_model.sql (77.84ms)16742026/09/21 13:24:32 OK 20241026095416_initial_model.sql (77.91ms)16752026/09/21 13:24:32 OK 20251210153512_drop_unused_gin_index.sql (3.66ms)16762026/09/21 13:24:32 OK 20251210153512_drop_unused_gin_index.sql (9.72ms)16772026/09/21 13:24:32 OK 20251218171726_add_pins.sql (22.31ms)16782026/09/21 13:24:32 OK 20251218171726_add_pins.sql (23ms)16792026/09/21 13:24:32 OK 20260628120000_add_object_size_and_stats.sql (23.73ms)16802026/09/21 13:24:32 OK 20260628120000_add_object_size_and_stats.sql (33.99ms)16812026/09/21 13:24:32 INFO Received uploads request method=POST path=/api/pending_closures16822026-09-21 13:24:32.495 UTC [38911] ERROR: relation "goose_db_version" does not exist at character 3616832026-09-21 13:24:32.495 UTC [38911] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16842026/09/21 13:24:32 OK 20260905000000_add_claims.sql (34.14ms)16852026/09/21 13:24:32 OK 20260905000000_add_claims.sql (16.75ms)16862026/09/21 13:24:32 OK 20260920000000_drop_claims.sql (4.32ms)16872026/09/21 13:24:32 goose: successfully migrated database to version: 2026092000000016882026/09/21 13:24:32 OK 20260920000000_drop_claims.sql (3.88ms)16892026/09/21 13:24:32 goose: successfully migrated database to version: 2026092000000016902026/09/21 13:24:32 OK 1_commit_pending_closure.sql (2.98ms)16912026/09/21 13:24:32 OK 1_commit_pending_closure.sql (2.42ms)16922026/09/21 13:24:32 OK 2_object_stats_trigger.sql (465.25µs)16932026/09/21 13:24:32 goose: up to current file version: 216942026/09/21 13:24:32 OK 2_object_stats_trigger.sql (497.29µs)16952026/09/21 13:24:32 goose: up to current file version: 21696=== NAME TestOrphanedObjectsGC1697 orphaned_objects_gc_test.go:290: GC Test Summary:1698 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A1699 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B1700 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)1701 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)1702 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects1703--- PASS: TestOrphanedObjectsGC (2.48s)1704=== CONT TestGracefulShutdownDrainsInflight17052026/09/21 13:24:32 INFO Starting HTTP server address=127.0.0.1:5956117062026/09/21 13:24:32 INFO Shutdown signal received, draining in-flight requests timeout=10s17072026-09-21 13:24:32.571 UTC [38912] ERROR: relation "goose_db_version" does not exist at character 3617082026-09-21 13:24:32.571 UTC [38912] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17092026/09/21 13:24:32 OK 20241026095416_initial_model.sql (68.19ms)17102026/09/21 13:24:32 OK 20251210153512_drop_unused_gin_index.sql (1.59ms)17112026/09/21 13:24:32 OK 20251218171726_add_pins.sql (13.85ms)17122026/09/21 13:24:32 OK 20260628120000_add_object_size_and_stats.sql (11.34ms)1713--- PASS: TestGracefulShutdownDrainsInflight (0.07s)1714=== CONT TestGCTaskStore_Fail1715--- PASS: TestGCTaskStore_Fail (0.00s)1716=== CONT TestGCTaskStore_ConflictDifferentParams1717--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)1718=== CONT TestGCTaskStore_CompletedAllowsNewTask1719--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)1720=== CONT TestGCTaskStore_GetReturnsLatest1721--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)1722=== CONT TestGCTaskStore_GetEmpty1723--- PASS: TestGCTaskStore_GetEmpty (0.00s)1724=== CONT TestGCTaskStore_StartNew1725--- PASS: TestGCTaskStore_StartNew (0.00s)1726=== CONT TestGCTaskStore_DeduplicateSameParams1727--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)1728=== CONT TestGCMetrics17292026/09/21 13:24:32 INFO Received cleanup request method=DELETE path=/api/pending_closures17302026/09/21 13:24:32 INFO Aborted multipart uploads count=117312026/09/21 13:24:32 OK 20260905000000_add_claims.sql (55.76ms)1732--- PASS: TestMultipartCleanup (1.32s)1733=== CONT TestGCBugBareHashReferences17342026/09/21 13:24:32 OK 20260920000000_drop_claims.sql (23.58ms)17352026/09/21 13:24:32 goose: successfully migrated database to version: 2026092000000017362026-09-21 13:24:32.686 UTC [38914] ERROR: relation "goose_db_version" does not exist at character 3617372026-09-21 13:24:32.686 UTC [38914] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17382026/09/21 13:24:32 OK 20241026095416_initial_model.sql (92.85ms)17392026/09/21 13:24:32 OK 1_commit_pending_closure.sql (2.35ms)17402026/09/21 13:24:32 OK 20251210153512_drop_unused_gin_index.sql (1.24ms)17412026/09/21 13:24:32 OK 2_object_stats_trigger.sql (819.88µs)17422026/09/21 13:24:32 goose: up to current file version: 217432026/09/21 13:24:32 OK 20251218171726_add_pins.sql (7.91ms)17442026/09/21 13:24:32 OK 20260628120000_add_object_size_and_stats.sql (19.66ms)17452026/09/21 13:24:32 OK 20260905000000_add_claims.sql (2.75ms)17462026/09/21 13:24:32 OK 20260920000000_drop_claims.sql (6.93ms)17472026/09/21 13:24:32 goose: successfully migrated database to version: 2026092000000017482026/09/21 13:24:32 OK 1_commit_pending_closure.sql (1.16ms)17492026/09/21 13:24:32 OK 2_object_stats_trigger.sql (248.17µs)17502026/09/21 13:24:32 goose: up to current file version: 217512026/09/21 13:24:32 OK 20241026095416_initial_model.sql (38.18ms)17522026/09/21 13:24:32 OK 20251210153512_drop_unused_gin_index.sql (1.55ms)17532026/09/21 13:24:32 OK 20251218171726_add_pins.sql (6.87ms)17542026/09/21 13:24:32 OK 20260628120000_add_object_size_and_stats.sql (25.58ms)1755=== NAME TestClientIntegration1756 client_integration_test.go:286: Created store path: /nix/var/nix/builds/nix-38446-2842733125/TestClientIntegration1298531566/002/store/lw2rair1ci7yl2ggv3fr3lwg59nxd92v-test-file.txt17572026/09/21 13:24:32 OK 20260905000000_add_claims.sql (11.97ms)17582026/09/21 13:24:32 OK 20260920000000_drop_claims.sql (14.65ms)17592026/09/21 13:24:32 goose: successfully migrated database to version: 2026092000000017602026/09/21 13:24:32 OK 1_commit_pending_closure.sql (1.39ms)17612026/09/21 13:24:32 OK 2_object_stats_trigger.sql (280.42µs)17622026/09/21 13:24:32 goose: up to current file version: 217632026/09/21 13:24:32 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"17642026/09/21 13:24:32 INFO Received uploads request method=POST path=/api/pending_closures17652026/09/21 13:24:32 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)17662026/09/21 13:24:32 INFO Uploading lw2rair1ci7yl2ggv3fr3lwg59nxd92v-test-file.txt (152B)17672026/09/21 13:24:32 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"17682026/09/21 13:24:32 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign17692026/09/21 13:24:32 WARN Failed to register uploaded object key=lw2rair1ci7yl2ggv3fr3lwg59nxd92v.ls error="server returned 404: 404 page not found\n"17702026/09/21 13:24:32 INFO Signed narinfos id=1 count=117712026/09/21 13:24:32 INFO Uploading 1 narinfos1772=== NAME TestClientMultipleUploads1773 client_integration_test.go:358: Created store path 0: /nix/var/nix/builds/nix-38446-2842733125/TestClientMultipleUploads860115928/001/store/mf47g301x1r9vzin4r230lw641q7g9za-test-file-0.txt17742026/09/21 13:24:32 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete17752026/09/21 13:24:32 WARN Failed to register uploaded object key=lw2rair1ci7yl2ggv3fr3lwg59nxd92v.narinfo error="server returned 404: 404 page not found\n"17762026/09/21 13:24:32 INFO Completed upload id=117772026/09/21 13:24:32 INFO Upload complete. (157ms)17782026-09-21 13:24:32.999 UTC [38929] ERROR: relation "goose_db_version" does not exist at character 3617792026-09-21 13:24:32.999 UTC [38929] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1780--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (1.38s)1781=== CONT TestServerTLSConfig/no_client_CA1782=== CONT TestServerTLSConfig/not_a_PEM_file1783=== CONT TestServerTLSConfig/missing_CA_file1784--- PASS: TestServerTLSConfig (0.00s)1785 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1786 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)1787 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1788=== CONT TestCacheConfigHandler/full_config,_no_issuer1789=== CONT TestCacheConfigHandler/no_signing_keys1790=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1791=== NAME TestClientMultipleUploads1792 client_integration_test.go:358: Created store path 1: /nix/var/nix/builds/nix-38446-2842733125/TestClientMultipleUploads860115928/001/store/4v23kdmvi2qr5r4msr0zysrb7wvh8pyn-test-file-1.txt1793=== CONT TestCacheConfigHandler/no_cache_url_configured1794--- PASS: TestCacheConfigHandler (0.00s)1795 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)1796 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)1797 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)1798 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)1799=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure18002026/09/21 13:24:33 INFO Received uploads request method=POST path=/18012026/09/21 13:24:33 INFO All 1 paths already cached1802=== NAME TestClientIntegration1803 client_integration_test.go:312: Retrieved narinfo from S3:1804 StorePath: /nix/var/nix/builds/nix-38446-2842733125/TestClientIntegration1298531566/002/store/lw2rair1ci7yl2ggv3fr3lwg59nxd92v-test-file.txt1805 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1806 Compression: zstd1807 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11808 NarSize: 1521809 References: 1810 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11811 client_integration_test.go:313: Retrieved .ls file from S3 (compressed size: 77 bytes)1812 client_integration_test.go:313: Decompressed .ls content (64 bytes):1813 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1814 client_integration_test.go:316: Testing garbage collection...18152026/09/21 13:24:33 INFO Starting cleanup of old closures method=DELETE path=/api/closures18162026/09/21 13:24:33 INFO Garbage collection started18172026/09/21 13:24:33 OK 20241026095416_initial_model.sql (33.29ms)18182026/09/21 13:24:33 INFO Aborted multipart uploads count=018192026/09/21 13:24:33 WARN Force mode enabled - objects will be deleted immediately without grace period18202026/09/21 13:24:33 OK 20251210153512_drop_unused_gin_index.sql (7.47ms)1821=== NAME TestClientMultipleUploads1822 client_integration_test.go:358: Created store path 2: /nix/var/nix/builds/nix-38446-2842733125/TestClientMultipleUploads860115928/001/store/k1gn1yh2g35h1dqk0sa9gqavlsx171zb-test-file-2.txt18232026/09/21 13:24:33 OK 20251218171726_add_pins.sql (8.55ms)18242026/09/21 13:24:33 OK 20260628120000_add_object_size_and_stats.sql (14.43ms)18252026/09/21 13:24:33 OK 20260905000000_add_claims.sql (13.35ms)18262026/09/21 13:24:33 OK 20260920000000_drop_claims.sql (8.13ms)18272026/09/21 13:24:33 goose: successfully migrated database to version: 2026092000000018282026/09/21 13:24:33 OK 1_commit_pending_closure.sql (931.42µs)18292026/09/21 13:24:33 OK 2_object_stats_trigger.sql (296.29µs)18302026/09/21 13:24:33 goose: up to current file version: 218312026/09/21 13:24:33 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"18322026/09/21 13:24:33 INFO Received uploads request method=POST path=/api/pending_closures18332026/09/21 13:24:33 INFO Received uploads request method=POST path=/api/pending_closures18342026/09/21 13:24:33 INFO Received uploads request method=POST path=/api/pending_closures18352026/09/21 13:24:33 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)18362026/09/21 13:24:33 INFO Uploading mf47g301x1r9vzin4r230lw641q7g9za-test-file-0.txt (160B)18372026/09/21 13:24:33 INFO Uploading 4v23kdmvi2qr5r4msr0zysrb7wvh8pyn-test-file-1.txt (160B)18382026/09/21 13:24:33 INFO Uploading k1gn1yh2g35h1dqk0sa9gqavlsx171zb-test-file-2.txt (160B)18392026/09/21 13:24:33 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"18402026/09/21 13:24:33 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"18412026/09/21 13:24:33 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"18422026/09/21 13:24:33 WARN Failed to register uploaded object key=k1gn1yh2g35h1dqk0sa9gqavlsx171zb.ls error="server returned 404: 404 page not found\n"18432026/09/21 13:24:33 WARN Failed to register uploaded object key=mf47g301x1r9vzin4r230lw641q7g9za.ls error="server returned 404: 404 page not found\n"18442026/09/21 13:24:33 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign18452026-09-21 13:24:33.232 UTC [38947] ERROR: relation "goose_db_version" does not exist at character 3618462026-09-21 13:24:33.232 UTC [38947] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18472026/09/21 13:24:33 WARN Failed to register uploaded object key=4v23kdmvi2qr5r4msr0zysrb7wvh8pyn.ls error="server returned 404: 404 page not found\n"18482026/09/21 13:24:33 INFO Signed narinfos id=1 count=118492026/09/21 13:24:33 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign18502026/09/21 13:24:33 INFO Signed narinfos id=2 count=118512026/09/21 13:24:33 INFO Received sign narinfos request method=POST path=/api/pending_closures/3/sign18522026/09/21 13:24:33 INFO Signed narinfos id=3 count=118532026/09/21 13:24:33 INFO Uploading 3 narinfos18542026/09/21 13:24:33 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=018552026/09/21 13:24:33 WARN Failed to register uploaded object key=mf47g301x1r9vzin4r230lw641q7g9za.narinfo error="server returned 404: 404 page not found\n"18562026/09/21 13:24:33 WARN Failed to register uploaded object key=k1gn1yh2g35h1dqk0sa9gqavlsx171zb.narinfo error="server returned 404: 404 page not found\n"18572026/09/21 13:24:33 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete18582026/09/21 13:24:33 WARN Failed to register uploaded object key=4v23kdmvi2qr5r4msr0zysrb7wvh8pyn.narinfo error="server returned 404: 404 page not found\n"1859=== NAME TestNARDeduplicationMetadataUploadBug1860 metadata_upload_test.go:48: First store path: /nix/var/nix/builds/nix-38446-2842733125/TestNARDeduplicationMetadataUploadBug1309779806/001/store/pbmsb4q9ql81lhs41jlgkcs4hv8cnzm6-file1.txt18612026/09/21 13:24:33 INFO Vacuumed table table=pending_closures18622026-09-21 13:24:33.247 UTC [38948] ERROR: relation "goose_db_version" does not exist at character 3618632026-09-21 13:24:33.247 UTC [38948] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18642026/09/21 13:24:33 INFO Completed upload id=118652026/09/21 13:24:33 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete18662026/09/21 13:24:33 INFO Completed upload id=218672026/09/21 13:24:33 INFO Received complete upload request method=POST path=/api/pending_closures/3/complete18682026/09/21 13:24:33 INFO Completed upload id=318692026/09/21 13:24:33 INFO Upload complete. (161ms)1870=== NAME TestClientMultipleUploads1871 client_integration_test.go:369: Uploaded 3 paths in 196.983208ms18722026/09/21 13:24:33 INFO Vacuumed table table=pending_objects18732026/09/21 13:24:33 INFO Vacuumed table table=multipart_uploads18742026/09/21 13:24:33 INFO Vacuumed table table=closures1875--- PASS: TestClientMultipleUploads (1.79s)1876=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts18772026/09/21 13:24:33 INFO Received request for more parts method=POST path=/18782026/09/21 13:24:33 INFO Vacuumed table table=objects1879=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart18802026/09/21 13:24:33 INFO Received complete multipart upload request method=POST path=/1881=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info18822026/09/21 13:24:33 INFO Received uploads request method=POST path=/1883=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key18842026/09/21 13:24:33 INFO Received complete multipart upload request method=POST path=/1885=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key18862026/09/21 13:24:33 INFO Received request for more parts method=POST path=/1887=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal18882026/09/21 13:24:33 INFO Received uploads request method=POST path=/1889--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)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 TestIsValidUploadKey/narinfo1895=== CONT TestIsValidUploadKey/realisation_plus_in_output1896=== CONT TestIsValidUploadKey/unknown_type1897=== CONT TestIsValidUploadKey/empty_key1898=== CONT TestIsValidUploadKey/absolute1899=== CONT TestIsValidUploadKey/traversal_nar1900=== CONT TestIsValidUploadKey/traversal1901=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1902=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1903=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1904=== CONT TestIsValidUploadKey/index.html1905=== CONT TestIsValidUploadKey/nix-cache-info1906=== CONT TestIsValidUploadKey/build_log_home-manager_file1907=== CONT TestIsValidUploadKey/realisation1908=== CONT TestIsValidUploadKey/build_log_equals1909=== CONT TestIsValidUploadKey/build_log_question_mark1910=== CONT TestIsValidUploadKey/build_log_plus_in_name1911=== CONT TestIsValidUploadKey/nar_plain1912=== CONT TestIsValidUploadKey/build_log1913=== CONT TestIsValidUploadKey/listing1914=== CONT TestIsValidUploadKey/nar_xz1915=== CONT TestIsValidUploadKey/nar_zst1916--- PASS: TestIsValidUploadKey (0.00s)1917 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1918 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1919 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1920 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1921 --- PASS: TestIsValidUploadKey/absolute (0.00s)1922 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1923 --- PASS: TestIsValidUploadKey/traversal (0.00s)1924 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1925 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1926 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1927 --- PASS: TestIsValidUploadKey/index.html (0.00s)1928 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1929 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1930 --- PASS: TestIsValidUploadKey/realisation (0.00s)1931 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1932 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1933 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1934 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1935 --- PASS: TestIsValidUploadKey/build_log (0.00s)1936 --- PASS: TestIsValidUploadKey/listing (0.00s)1937 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1938 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1939=== CONT TestProxyWriteTimeout/narinfo1940=== CONT TestProxyWriteTimeout/10_GiB_nar1941=== CONT TestProxyWriteTimeout/unknown_size1942=== CONT TestProxyWriteTimeout/1_GiB_nar1943--- PASS: TestProxyWriteTimeout (0.00s)1944 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1945 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1946 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1947 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1948=== CONT TestService_RequireScope_OIDC/builder_may_write1949=== CONT TestService_RequireScope_OIDC/static_token_may_admin1950=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read1951=== CONT TestService_RequireScope_OIDC/writer_implies_read1952=== CONT TestService_RequireScope_OIDC/reader_may_read1953=== CONT TestService_RequireScope_OIDC/static_token_may_write1954=== CONT TestService_RequireScope_OIDC/ops_may_not_write1955=== CONT TestService_RequireScope_OIDC/reader_may_not_write1956=== CONT TestService_RequireScope_OIDC/ops_may_admin1957=== CONT TestService_RequireScope_OIDC/builder_may_not_admin1958=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token1959=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected19602026/09/21 13:24:33 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]1961=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1962=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected19632026/09/21 13:24:33 WARN Authentication failed token_preview=eyJhbGciOi...2lClMw3X-Q token_length=702 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]1964=== CONT TestResolveDBConnectionString/flag_wins1965=== CONT TestResolveDBConnectionString/PGHOST_allows_empty1966=== CONT TestResolveDBConnectionString/nothing_configured1967=== CONT TestResolveDBConnectionString/missing_file_is_an_error1968=== CONT TestResolveDBConnectionString/file_when_flag_empty1969=== CONT TestIsValidCachePath/narinfo1970=== CONT TestIsValidCachePath/index.html1971=== CONT TestIsValidCachePath/short_hash1972=== CONT TestIsValidCachePath/wrong_extension1973=== CONT TestIsValidCachePath/leading_slash1974=== CONT TestIsValidCachePath/empty1975=== CONT TestIsValidCachePath/random_path1976=== CONT TestIsValidCachePath/invalid_char_u1977=== CONT TestIsValidCachePath/invalid_char_e1978=== CONT TestIsValidCachePath/traversal_in_middle1979=== CONT TestIsValidCachePath/traversal_parent1980=== CONT TestIsValidCachePath/nar_uncompressed1981=== CONT TestIsValidCachePath/nix-cache-info1982=== CONT TestIsValidCachePath/realisation1983=== CONT TestIsValidCachePath/log1984=== CONT TestIsValidCachePath/ls1985=== CONT TestIsValidCachePath/nar_xz1986=== CONT TestIsValidCachePath/nar_bz21987=== CONT TestIsValidCachePath/nar_zst1988=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1989--- PASS: TestIsValidCachePath (0.00s)1990 --- PASS: TestIsValidCachePath/narinfo (0.00s)1991 --- PASS: TestIsValidCachePath/index.html (0.00s)1992 --- PASS: TestIsValidCachePath/short_hash (0.00s)1993 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1994 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1995 --- PASS: TestIsValidCachePath/empty (0.00s)1996 --- PASS: TestIsValidCachePath/random_path (0.00s)1997 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1998 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1999 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)2000 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)2001 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)2002 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)2003 --- PASS: TestIsValidCachePath/realisation (0.00s)2004 --- PASS: TestIsValidCachePath/log (0.00s)2005 --- PASS: TestIsValidCachePath/ls (0.00s)2006 --- PASS: TestIsValidCachePath/nar_xz (0.00s)2007 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)2008 --- PASS: TestIsValidCachePath/nar_zst (0.00s)2009 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)2010=== CONT TestParseSingleRange/none2011=== CONT TestParseSingleRange/open-ended2012=== CONT TestParseSingleRange/start_far_past_EOF2013=== CONT TestParseSingleRange/start_past_EOF2014=== CONT TestParseSingleRange/single_byte2015=== CONT TestParseSingleRange/suffix_exceeds_size2016=== CONT TestParseSingleRange/suffix2017=== CONT TestParseSingleRange/end_clamped_to_size2018=== CONT TestParseSingleRange/malformed_both_empty2019=== CONT TestParseSingleRange/closed2020=== CONT TestParseSingleRange/malformed_end_before_start2021=== CONT TestParseSingleRange/multi-range_ignored2022=== CONT TestParseSingleRange/malformed_no_dash2023=== CONT TestParseSingleRange/unknown_unit2024--- PASS: TestParseSingleRange (0.00s)2025 --- PASS: TestParseSingleRange/none (0.00s)2026 --- PASS: TestParseSingleRange/open-ended (0.00s)2027 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)2028 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)2029 --- PASS: TestParseSingleRange/single_byte (0.00s)2030 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)2031 --- PASS: TestParseSingleRange/suffix (0.00s)2032 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)2033 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)2034 --- PASS: TestParseSingleRange/closed (0.00s)2035 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)2036 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)2037 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)2038 --- PASS: TestParseSingleRange/unknown_unit (0.00s)2039=== CONT TestClientErrorHandling/InvalidStorePath2040--- PASS: TestService_RequireScope_OIDC (1.51s)2041 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)2042 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)2043 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)2044 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)2045 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)2046 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)2047 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)2048 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)2049 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)2050 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)2051--- PASS: TestService_AuthMiddleware_OIDC (1.94s)2052 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)2053 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)2054 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)2055 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)2056--- PASS: TestResolveDBConnectionString (0.01s)2057 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)2058 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)2059 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)2060 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)2061 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)20622026/09/21 13:24:33 OK 20241026095416_initial_model.sql (51.71ms)2063--- PASS: TestUploadHandlersRejectOversizedBody (0.02s)2064 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.29s)2065 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.02s)2066 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.02s)2067=== CONT TestClientErrorHandling/ServerNotAvailable20682026/09/21 13:24:33 OK 20251210153512_drop_unused_gin_index.sql (6.81ms)20692026/09/21 13:24:33 WARN readiness check failed error="closed pool"2070--- PASS: TestService_readinessHandler (1.55s)2071=== CONT TestClientErrorHandling/InvalidAuthToken20722026/09/21 13:24:33 OK 20241026095416_initial_model.sql (54.56ms)20732026/09/21 13:24:33 OK 20251218171726_add_pins.sql (3.28ms)20742026/09/21 13:24:33 OK 20251210153512_drop_unused_gin_index.sql (5.15ms)20752026/09/21 13:24:33 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"20762026/09/21 13:24:33 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=02077=== NAME TestPinProtectsFromGC2078 client_integration_test.go:794: Pin successfully protected closure from garbage collection20792026/09/21 13:24:33 OK 20260628120000_add_object_size_and_stats.sql (11.02ms)20802026/09/21 13:24:33 OK 20251218171726_add_pins.sql (14.73ms)20812026/09/21 13:24:33 OK 20260905000000_add_claims.sql (14.84ms)20822026/09/21 13:24:33 OK 20260920000000_drop_claims.sql (14.17ms)20832026/09/21 13:24:33 goose: successfully migrated database to version: 202609200000002084--- PASS: TestPinProtectsFromGC (5.05s)20852026/09/21 13:24:33 OK 20260628120000_add_object_size_and_stats.sql (22.67ms)20862026/09/21 13:24:33 INFO Received uploads request method=POST path=/api/pending_closures20872026/09/21 13:24:33 OK 1_commit_pending_closure.sql (3.25ms)20882026/09/21 13:24:33 OK 2_object_stats_trigger.sql (428.42µs)20892026/09/21 13:24:33 goose: up to current file version: 220902026/09/21 13:24:33 OK 20260905000000_add_claims.sql (22.6ms)20912026/09/21 13:24:33 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)20922026/09/21 13:24:33 INFO Uploading pbmsb4q9ql81lhs41jlgkcs4hv8cnzm6-file1.txt (160B)20932026/09/21 13:24:33 OK 20260920000000_drop_claims.sql (14.86ms)20942026/09/21 13:24:33 goose: successfully migrated database to version: 2026092000000020952026/09/21 13:24:33 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"20962026/09/21 13:24:33 OK 1_commit_pending_closure.sql (1.39ms)20972026/09/21 13:24:33 OK 2_object_stats_trigger.sql (2.16ms)20982026/09/21 13:24:33 goose: up to current file version: 220992026/09/21 13:24:33 WARN Failed to register uploaded object key=pbmsb4q9ql81lhs41jlgkcs4hv8cnzm6.ls error="server returned 404: 404 page not found\n"21002026/09/21 13:24:33 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign21012026/09/21 13:24:33 INFO Signed narinfos id=1 count=121022026/09/21 13:24:33 INFO Uploading 1 narinfos21032026/09/21 13:24:33 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete21042026/09/21 13:24:33 WARN Failed to register uploaded object key=pbmsb4q9ql81lhs41jlgkcs4hv8cnzm6.narinfo error="server returned 404: 404 page not found\n"21052026/09/21 13:24:33 INFO Completed upload id=121062026/09/21 13:24:33 INFO Upload complete. (139ms)2107=== NAME TestNARDeduplicationMetadataUploadBug2108 metadata_upload_test.go:54: Retrieved narinfo from S3:2109 StorePath: /nix/var/nix/builds/nix-38446-2842733125/TestNARDeduplicationMetadataUploadBug1309779806/001/store/pbmsb4q9ql81lhs41jlgkcs4hv8cnzm6-file1.txt2110 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst2111 Compression: zstd2112 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf2113 NarSize: 1602114 References: 2115 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf2116 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)2117 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):2118 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}21192026/09/21 13:24:33 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/present2120--- PASS: TestService_healthCheckHandler (1.19s)2121=== NAME TestNARDeduplicationMetadataUploadBug2122 metadata_upload_test.go:64: Second store path (same content): /nix/var/nix/builds/nix-38446-2842733125/TestNARDeduplicationMetadataUploadBug1309779806/001/store/zdxbbrp8pfrn0d4rwfpajvw0vvfj6lpa-file2.txt21232026/09/21 13:24:33 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=181.365892ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/objects/present21242026/09/21 13:24:33 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"21252026/09/21 13:24:33 INFO Received uploads request method=POST path=/api/pending_closures21262026/09/21 13:24:33 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)21272026/09/21 13:24:33 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign21282026/09/21 13:24:33 INFO Signed narinfos id=2 count=121292026/09/21 13:24:33 INFO Uploading 1 narinfos21302026/09/21 13:24:33 WARN Failed to register uploaded object key=zdxbbrp8pfrn0d4rwfpajvw0vvfj6lpa.ls error="server returned 404: 404 page not found\n"21312026/09/21 13:24:33 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete21322026/09/21 13:24:33 WARN Failed to register uploaded object key=zdxbbrp8pfrn0d4rwfpajvw0vvfj6lpa.narinfo error="server returned 404: 404 page not found\n"21332026/09/21 13:24:33 INFO Completed upload id=221342026/09/21 13:24:33 INFO Upload complete. (98ms)2135 metadata_upload_test.go:76: Retrieved narinfo from S3:2136 StorePath: /nix/var/nix/builds/nix-38446-2842733125/TestNARDeduplicationMetadataUploadBug1309779806/001/store/zdxbbrp8pfrn0d4rwfpajvw0vvfj6lpa-file2.txt2137 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst2138 Compression: zstd2139 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf2140 NarSize: 1602141 References: 2142 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf2143 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)2144 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):2145 {"version":1,"root":{"type":"regular","size":44}}2146--- PASS: TestNARDeduplicationMetadataUploadBug (1.95s)21472026/09/21 13:24:33 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=381.369968ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/objects/present21482026/09/21 13:24:33 INFO Aborted multipart uploads count=021492026/09/21 13:24:33 WARN Force mode enabled - objects will be deleted immediately without grace period21502026/09/21 13:24:33 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=021512026/09/21 13:24:33 INFO Vacuumed table table=pending_closures21522026/09/21 13:24:33 INFO Vacuumed table table=pending_objects21532026-09-21 13:24:33.752 UTC [38972] ERROR: relation "goose_db_version" does not exist at character 3621542026-09-21 13:24:33.752 UTC [38972] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC21552026/09/21 13:24:33 INFO Vacuumed table table=multipart_uploads21562026/09/21 13:24:33 INFO Vacuumed table table=closures21572026/09/21 13:24:33 INFO Vacuumed table table=objects2158--- PASS: TestGCMetrics (1.12s)21592026-09-21 13:24:33.757 UTC [38973] ERROR: relation "goose_db_version" does not exist at character 3621602026-09-21 13:24:33.757 UTC [38973] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC21612026/09/21 13:24:33 OK 20241026095416_initial_model.sql (4.07ms)21622026/09/21 13:24:33 OK 20241026095416_initial_model.sql (4.08ms)21632026/09/21 13:24:33 OK 20251210153512_drop_unused_gin_index.sql (445.71µs)21642026/09/21 13:24:33 OK 20251210153512_drop_unused_gin_index.sql (355.38µs)21652026/09/21 13:24:33 OK 20251218171726_add_pins.sql (814µs)21662026/09/21 13:24:33 OK 20251218171726_add_pins.sql (794.08µs)21672026/09/21 13:24:33 OK 20260628120000_add_object_size_and_stats.sql (1.62ms)21682026/09/21 13:24:33 OK 20260628120000_add_object_size_and_stats.sql (1.82ms)21692026/09/21 13:24:33 OK 20260905000000_add_claims.sql (1.17ms)21702026/09/21 13:24:33 OK 20260905000000_add_claims.sql (1.37ms)21712026/09/21 13:24:33 OK 20260920000000_drop_claims.sql (658.46µs)21722026/09/21 13:24:33 goose: successfully migrated database to version: 2026092000000021732026/09/21 13:24:33 OK 20260920000000_drop_claims.sql (694.54µs)21742026/09/21 13:24:33 goose: successfully migrated database to version: 2026092000000021752026/09/21 13:24:33 OK 1_commit_pending_closure.sql (885.58µs)21762026/09/21 13:24:33 OK 2_object_stats_trigger.sql (193.75µs)21772026/09/21 13:24:33 goose: up to current file version: 221782026/09/21 13:24:33 OK 1_commit_pending_closure.sql (773.17µs)21792026/09/21 13:24:33 OK 2_object_stats_trigger.sql (192.29µs)21802026/09/21 13:24:33 goose: up to current file version: 22181--- PASS: TestGCBugBareHashReferences (1.16s)2182=== NAME TestOrphanedObjectsGCStressTest2183 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains2184 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion21852026/09/21 13:24:34 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"21862026/09/21 13:24:34 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"21872026/09/21 13:24:34 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"21882026/09/21 13:24:34 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=876.425019ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2189 orphaned_objects_gc_test.go:509: Stress test completed successfully:2190 orphaned_objects_gc_test.go:510: - Active objects preserved: 202191 orphaned_objects_gc_test.go:511: - Objects deleted: 2102192 orphaned_objects_gc_test.go:512: - Total GC'd: 2102193--- PASS: TestOrphanedObjectsGCStressTest (4.12s)21942026/09/21 13:24:34 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.48686848s error="Post \"http://localhost:19999/api/objects/present\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/objects/present21952026/09/21 13:24:35 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=02196=== NAME TestClientIntegration2197 client_integration_test.go:323: Objects in database after GC:2198 client_integration_test.go:323: Successfully deleted all objects with GC --force2199--- PASS: TestClientIntegration (3.58s)22002026/09/21 13:24:36 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-config22012026/09/21 13:24:36 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=180.218596ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22022026/09/21 13:24:36 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=385.612617ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22032026/09/21 13:24:37 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=834.346467ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22042026/09/21 13:24:38 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.691666026s error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22052026/09/21 13:24:39 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"22062026/09/21 13:24:39 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_closures22072026/09/21 13:24:39 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=190.123546ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22082026/09/21 13:24:40 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=403.724253ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22092026/09/21 13:24:40 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=744.144666ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22102026/09/21 13:24:41 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.544399224s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2211--- PASS: TestClientErrorHandling (0.00s)2212 --- PASS: TestClientErrorHandling/InvalidStorePath (0.76s)2213 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.78s)2214 --- PASS: TestClientErrorHandling/ServerNotAvailable (9.51s)2215PASS2216{"timestamp":"2026-09-21T13:24:42.829378Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:59479","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(8)"}22172026-09-21 13:24:42.921 UTC [38529] LOG: received smart shutdown request22182026-09-21 13:24:42.922 UTC [38529] LOG: background worker "logical replication launcher" (PID 38540) exited with exit code 122192026-09-21 13:24:42.926 UTC [38535] LOG: shutting down22202026-09-21 13:24:42.926 UTC [38535] LOG: checkpoint starting: shutdown immediate22212026-09-21 13:24:43.992 UTC [38535] LOG: checkpoint complete: wrote 13146 buffers (80.2%), wrote 3 SLRU buffers; 0 WAL file(s) added, 0 removed, 16 recycled; write=0.743 s, sync=0.317 s, total=1.067 s; sync files=18738, longest=0.001 s, average=0.001 s; distance=260142 kB, estimate=260142 kB; lsn=0/11598A40, redo lsn=0/11598A4022222026-09-21 13:24:43.997 UTC [38529] LOG: database system is shut down2223Running OIDC tests...2224=== RUN TestGlobMatch2225=== PAUSE TestGlobMatch2226=== RUN TestAudienceForIssuer2227=== PAUSE TestAudienceForIssuer2228=== RUN TestValidateToken_ValidToken2229=== PAUSE TestValidateToken_ValidToken2230=== RUN TestValidateToken_WrongAudience2231=== PAUSE TestValidateToken_WrongAudience2232=== RUN TestValidateToken_Expired2233=== PAUSE TestValidateToken_Expired2234=== RUN TestValidateToken_BoundClaimsMismatch2235=== PAUSE TestValidateToken_BoundClaimsMismatch2236=== RUN TestValidateToken_BoundSubjectMismatch2237=== PAUSE TestValidateToken_BoundSubjectMismatch2238=== RUN TestValidateToken_MultipleProviders2239=== PAUSE TestValidateToken_MultipleProviders2240=== RUN TestValidateToken_NoMatchingProvider2241=== PAUSE TestValidateToken_NoMatchingProvider2242=== RUN TestValidateToken_KubernetesServiceAccount2243=== PAUSE TestValidateToken_KubernetesServiceAccount2244=== RUN TestNewValidator_KubernetesRequiresCA2245=== PAUSE TestNewValidator_KubernetesRequiresCA2246=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2247=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2248=== RUN TestScopes_LegacyProviderDefaultsToWrite2249=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2250=== RUN TestScopes_Rules2251=== PAUSE TestScopes_Rules2252=== RUN TestScopes_ConfigValidation2253=== PAUSE TestScopes_ConfigValidation2254=== CONT TestGlobMatch2255=== CONT TestValidateToken_Expired2256=== RUN TestGlobMatch/foo_foo2257=== CONT TestValidateToken_NoMatchingProvider2258=== PAUSE TestGlobMatch/foo_foo2259=== RUN TestGlobMatch/foo_bar2260=== PAUSE TestGlobMatch/foo_bar2261=== RUN TestGlobMatch/*_2262=== PAUSE TestGlobMatch/*_2263=== RUN TestGlobMatch/*_anything2264=== PAUSE TestGlobMatch/*_anything2265=== RUN TestGlobMatch/foo*_foo2266=== PAUSE TestGlobMatch/foo*_foo2267=== RUN TestGlobMatch/foo*_foobar2268=== PAUSE TestGlobMatch/foo*_foobar2269=== RUN TestGlobMatch/foo*_bar2270=== PAUSE TestGlobMatch/foo*_bar2271=== RUN TestGlobMatch/*bar_bar2272=== PAUSE TestGlobMatch/*bar_bar2273=== CONT TestScopes_LegacyProviderDefaultsToWrite2274=== CONT TestAudienceForIssuer2275--- PASS: TestAudienceForIssuer (0.00s)2276=== CONT TestValidateToken_BoundSubjectMismatch2277=== CONT TestScopes_ConfigValidation2278=== CONT TestScopes_Rules2279=== CONT TestValidateToken_MultipleProviders2280=== RUN TestGlobMatch/*bar_foobar2281=== PAUSE TestGlobMatch/*bar_foobar2282=== RUN TestGlobMatch/*bar_foo2283=== PAUSE TestGlobMatch/*bar_foo2284=== RUN TestGlobMatch/foo*bar_foobar2285=== PAUSE TestGlobMatch/foo*bar_foobar2286=== RUN TestGlobMatch/foo*bar_foo123bar2287=== PAUSE TestGlobMatch/foo*bar_foo123bar2288=== RUN TestGlobMatch/foo*bar_foobarbaz2289=== PAUSE TestGlobMatch/foo*bar_foobarbaz2290=== RUN TestGlobMatch/*/*_foo/bar2291=== PAUSE TestGlobMatch/*/*_foo/bar2292=== RUN TestGlobMatch/*/*_foo2293=== PAUSE TestGlobMatch/*/*_foo2294=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2295=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2296=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02297=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02298=== RUN TestGlobMatch/refs/*/main_refs/heads/main2299=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2300=== RUN TestGlobMatch/fo?_foo2301=== PAUSE TestGlobMatch/fo?_foo2302=== RUN TestGlobMatch/fo?_fo2303=== PAUSE TestGlobMatch/fo?_fo2304=== RUN TestGlobMatch/fo?_fooo2305=== PAUSE TestGlobMatch/fo?_fooo2306=== RUN TestGlobMatch/?oo_foo2307=== PAUSE TestGlobMatch/?oo_foo2308=== RUN TestGlobMatch/?oo_boo2309=== PAUSE TestGlobMatch/?oo_boo2310=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2311=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2312=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2313=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2314=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2315=== CONT TestValidateToken_WrongAudience2316=== CONT TestValidateToken_ValidToken23172026/09/21 13:24:44 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:59641/oidc23182026/09/21 13:24:44 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:59634/oidc23192026/09/21 13:24:44 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:59633/oidc23202026/09/21 13:24:44 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:59638/oidc2321--- PASS: TestScopes_ConfigValidation (0.00s)2322=== CONT TestNewValidator_KubernetesRequiresCA23232026/09/21 13:24:44 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:59636/oidc23242026/09/21 13:24:44 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:59632/oidc23252026/09/21 13:24:44 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:59637/oidc23262026/09/21 13:24:44 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:59635/oidc23272026/09/21 13:24:44 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC12323282026/09/21 13:24:44 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:59640/oidc2329--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.01s)2330=== CONT TestValidateToken_KubernetesServiceAccount2331--- PASS: TestValidateToken_BoundSubjectMismatch (0.01s)2332=== CONT TestValidateToken_BoundClaimsMismatch2333--- PASS: TestValidateToken_Expired (0.01s)2334=== CONT TestGlobMatch/foo_foo2335=== CONT TestGlobMatch/*/*_foo/bar2336=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2337=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2338=== CONT TestGlobMatch/?oo_boo2339--- PASS: TestValidateToken_WrongAudience (0.01s)2340=== CONT TestGlobMatch/?oo_foo2341=== CONT TestGlobMatch/fo?_fo2342=== CONT TestGlobMatch/fo?_foo2343=== CONT TestGlobMatch/refs/*/main_refs/heads/main2344=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02345=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2346=== CONT TestGlobMatch/*/*_foo2347=== CONT TestGlobMatch/*bar_bar2348=== CONT TestGlobMatch/foo*bar_foobarbaz2349=== CONT TestGlobMatch/foo*bar_foo123bar2350=== CONT TestGlobMatch/foo*bar_foobar2351=== CONT TestGlobMatch/*bar_foo2352=== CONT TestGlobMatch/*bar_foobar2353=== CONT TestGlobMatch/foo*_foo2354=== CONT TestGlobMatch/foo*_bar2355=== CONT TestGlobMatch/foo*_foobar2356=== CONT TestGlobMatch/*_2357=== CONT TestGlobMatch/*_anything2358=== CONT TestGlobMatch/foo_bar2359=== CONT TestGlobMatch/fo?_fooo2360--- PASS: TestGlobMatch (0.00s)2361 --- PASS: TestGlobMatch/foo_foo (0.00s)2362 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2363 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2364 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2365 --- PASS: TestGlobMatch/?oo_boo (0.00s)2366 --- PASS: TestGlobMatch/?oo_foo (0.00s)2367 --- PASS: TestGlobMatch/fo?_fo (0.00s)2368 --- PASS: TestGlobMatch/fo?_foo (0.00s)2369 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2370 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2371 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2372 --- PASS: TestGlobMatch/*/*_foo (0.00s)2373 --- PASS: TestGlobMatch/*bar_bar (0.00s)2374 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2375 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2376 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2377 --- PASS: TestGlobMatch/*bar_foo (0.00s)2378 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2379 --- PASS: TestGlobMatch/foo*_foo (0.00s)2380 --- PASS: TestGlobMatch/foo*_bar (0.00s)2381 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2382 --- PASS: TestGlobMatch/*_ (0.00s)2383 --- PASS: TestGlobMatch/*_anything (0.00s)2384 --- PASS: TestGlobMatch/foo_bar (0.00s)2385 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2386--- PASS: TestValidateToken_ValidToken (0.01s)2387--- PASS: TestValidateToken_NoMatchingProvider (0.01s)23882026/09/21 13:24:44 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:59655/oidc2389--- PASS: TestValidateToken_MultipleProviders (0.01s)2390--- PASS: TestValidateToken_BoundClaimsMismatch (0.00s)23912026/09/21 13:24:44 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:596542392--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.01s)2393--- PASS: TestScopes_Rules (0.01s)23942026/09/21 13:24:44 http: TLS handshake error from 127.0.0.1:59652: remote error: tls: bad certificate2395--- PASS: TestNewValidator_KubernetesRequiresCA (0.01s)2396--- PASS: TestValidateToken_KubernetesServiceAccount (0.01s)2397PASS2398Running hook tests...2399=== RUN TestSendPathsEmpty2400=== PAUSE TestSendPathsEmpty2401=== RUN TestQueueEnqueueAndFetch2402=== PAUSE TestQueueEnqueueAndFetch2403=== RUN TestQueueDeduplication2404=== PAUSE TestQueueDeduplication2405=== RUN TestQueueRemove2406=== PAUSE TestQueueRemove2407=== RUN TestQueueFetchBatchLimit2408=== PAUSE TestQueueFetchBatchLimit2409=== RUN TestQueueRetryMovesToBack2410=== PAUSE TestQueueRetryMovesToBack2411=== RUN TestQueueFetchRemoveLifecycle2412=== PAUSE TestQueueFetchRemoveLifecycle2413=== RUN TestQueueConcurrentWriters2414=== PAUSE TestQueueConcurrentWriters2415=== RUN TestQueueRemoveLargeClosure2416=== PAUSE TestQueueRemoveLargeClosure2417=== RUN TestServerClientIntegration2418=== PAUSE TestServerClientIntegration2419=== RUN TestServerQueueError2420=== PAUSE TestServerQueueError2421=== RUN TestGetListenerSocketActivation2422 server_test.go:210: === RUN TestGetListenerSocketActivation2423 --- PASS: TestGetListenerSocketActivation (0.00s)2424 PASS2425 2426--- PASS: TestGetListenerSocketActivation (0.01s)2427=== RUN TestDrainIsolatesPoisonPath2428=== PAUSE TestDrainIsolatesPoisonPath2429=== RUN TestRunNotBlockedByPoisonHead2430=== PAUSE TestRunNotBlockedByPoisonHead2431=== RUN TestDrainGivesUpWhenServerDown2432=== PAUSE TestDrainGivesUpWhenServerDown2433=== RUN TestFailedPathPrunedByLaterClosure2434=== PAUSE TestFailedPathPrunedByLaterClosure2435=== RUN TestWorkerUploadsAndRemoves2436=== PAUSE TestWorkerUploadsAndRemoves2437=== RUN TestWorkerSkipsGCdPaths2438=== PAUSE TestWorkerSkipsGCdPaths2439=== RUN TestWorkerPrunesClosureDeps2440=== PAUSE TestWorkerPrunesClosureDeps2441=== RUN TestDrainTimeout2442=== PAUSE TestDrainTimeout2443=== CONT TestSendPathsEmpty2444=== CONT TestServerQueueError2445=== CONT TestQueueRemoveLargeClosure2446--- PASS: TestSendPathsEmpty (0.00s)2447=== CONT TestServerClientIntegration2448=== CONT TestQueueFetchBatchLimit2449=== CONT TestQueueRemove2450=== CONT TestQueueDeduplication2451=== CONT TestQueueEnqueueAndFetch2452=== CONT TestWorkerUploadsAndRemoves2453=== CONT TestDrainTimeout2454=== CONT TestQueueRetryMovesToBack24552026/09/21 13:24:45 ERROR Failed to queue paths error="permission denied" count=12456--- PASS: TestServerClientIntegration (0.00s)2457=== CONT TestWorkerPrunesClosureDeps2458--- PASS: TestServerQueueError (0.00s)2459=== CONT TestWorkerSkipsGCdPaths2460--- PASS: TestQueueDeduplication (0.01s)2461=== CONT TestQueueConcurrentWriters2462--- PASS: TestQueueEnqueueAndFetch (0.01s)2463=== CONT TestDrainGivesUpWhenServerDown24642026/09/21 13:24:45 INFO Upload queue status pending=224652026/09/21 13:24:45 INFO Uploading batch count=124662026/09/21 13:24:45 INFO Upload queue status pending=224672026/09/21 13:24:45 INFO Uploading batch count=224682026/09/21 13:24:45 WARN Store path no longer exists (garbage collected?), removing from queue path=/nix/var/nix/builds/nix-38446-2842733125/TestWorkerSkipsGCdPaths2091945605/002/nonexistent2469--- PASS: TestQueueRetryMovesToBack (0.01s)2470=== CONT TestFailedPathPrunedByLaterClosure24712026/09/21 13:24:45 INFO Uploading batch count=124722026/09/21 13:24:45 INFO Upload queue status pending=224732026/09/21 13:24:45 INFO Uploading batch count=22474--- PASS: TestQueueFetchBatchLimit (0.01s)2475=== CONT TestQueueFetchRemoveLifecycle2476--- PASS: TestQueueRemove (0.01s)2477=== CONT TestRunNotBlockedByPoisonHead24782026/09/21 13:24:45 INFO Uploading batch count=124792026/09/21 13:24:45 ERROR Upload failed error="upload failed" count=124802026/09/21 13:24:45 INFO Uploading batch count=224812026/09/21 13:24:45 ERROR Upload failed error="upload failed" count=224822026/09/21 13:24:45 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-38446-2842733125/TestDrainGivesUpWhenServerDown3379674910/002/a24832026/09/21 13:24:45 INFO Uploading batch count=124842026/09/21 13:24:45 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-38446-2842733125/TestDrainGivesUpWhenServerDown3379674910/002/b24852026/09/21 13:24:45 INFO Uploading batch count=124862026/09/21 13:24:45 INFO Uploading batch count=224872026/09/21 13:24:45 ERROR Upload failed error="upload failed" count=224882026/09/21 13:24:45 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-38446-2842733125/TestDrainGivesUpWhenServerDown3379674910/002/c24892026/09/21 13:24:45 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-38446-2842733125/TestDrainGivesUpWhenServerDown3379674910/002/d24902026/09/21 13:24:45 INFO Upload queue status pending=32491--- PASS: TestQueueFetchRemoveLifecycle (0.00s)2492=== CONT TestDrainIsolatesPoisonPath24932026/09/21 13:24:45 INFO Uploading batch count=124942026/09/21 13:24:45 ERROR Upload failed error="upload failed" count=124952026/09/21 13:24:45 INFO Uploading batch count=224962026/09/21 13:24:45 ERROR Upload failed error="upload failed" count=224972026/09/21 13:24:45 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-38446-2842733125/TestDrainGivesUpWhenServerDown3379674910/002/e24982026/09/21 13:24:45 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-38446-2842733125/TestDrainGivesUpWhenServerDown3379674910/002/f24992026/09/21 13:24:45 ERROR Drain finished with paths left in queue remaining=102500--- PASS: TestFailedPathPrunedByLaterClosure (0.00s)25012026/09/21 13:24:45 INFO Uploading batch count=425022026/09/21 13:24:45 ERROR Upload failed error="upload failed" count=425032026/09/21 13:24:45 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-38446-2842733125/TestDrainIsolatesPoisonPath3757450599/002/bbb2504--- PASS: TestDrainGivesUpWhenServerDown (0.01s)25052026/09/21 13:24:45 INFO Uploading batch count=125062026/09/21 13:24:45 ERROR Upload failed error="upload failed" count=125072026/09/21 13:24:45 INFO Uploading batch count=125082026/09/21 13:24:45 ERROR Upload failed error="upload failed" count=125092026/09/21 13:24:45 INFO Uploading batch count=125102026/09/21 13:24:45 ERROR Upload failed error="upload failed" count=125112026/09/21 13:24:45 ERROR Drain finished with paths left in queue remaining=12512--- PASS: TestDrainIsolatesPoisonPath (0.00s)2513--- PASS: TestWorkerPrunesClosureDeps (0.03s)2514--- PASS: TestWorkerSkipsGCdPaths (0.03s)2515--- PASS: TestWorkerUploadsAndRemoves (0.03s)2516--- PASS: TestQueueRemoveLargeClosure (0.06s)2517--- PASS: TestQueueConcurrentWriters (0.12s)25182026/09/21 13:24:45 ERROR Upload failed error="context deadline exceeded" count=225192026/09/21 13:24:45 ERROR Drain finished with paths left in queue remaining=42520--- PASS: TestDrainTimeout (0.21s)25212026/09/21 13:24:46 INFO Uploading batch count=125222026/09/21 13:24:46 INFO Uploading batch count=125232026/09/21 13:24:46 INFO Uploading batch count=125242026/09/21 13:24:46 ERROR Upload failed error="upload failed" count=125252026/09/21 13:24:46 INFO Uploading batch count=125262026/09/21 13:24:46 ERROR Upload failed error="upload failed" count=125272026/09/21 13:24:46 INFO Uploading batch count=125282026/09/21 13:24:46 ERROR Upload failed error="upload failed" count=125292026/09/21 13:24:46 INFO Uploading batch count=125302026/09/21 13:24:46 ERROR Upload failed error="upload failed" count=125312026/09/21 13:24:46 ERROR Drain finished with paths left in queue remaining=12532--- PASS: TestRunNotBlockedByPoisonHead (1.01s)2533PASS