niks3-go-unit-tests
checks.aarch64-darwin.go-unit-tests
· build #237
· raw
1Running client tests...2=== RUN TestDoServerRequestAttachesToken3=== PAUSE TestDoServerRequestAttachesToken4=== RUN TestRegisterUploadedObjectReusesConnections5=== PAUSE TestRegisterUploadedObjectReusesConnections6=== RUN TestCaseHackSuffix7=== PAUSE TestCaseHackSuffix8=== RUN TestFilterOversizedClosures9=== PAUSE TestFilterOversizedClosures10=== RUN TestUploadMultipart_PartsInParallel11=== PAUSE TestUploadMultipart_PartsInParallel12=== RUN TestPartSizeForNAR13=== PAUSE TestPartSizeForNAR14=== RUN TestUploadMultipart_SupersededByPeer15=== PAUSE TestUploadMultipart_SupersededByPeer16=== RUN TestDumpPathCaseHackMatchesNix17--- PASS: TestDumpPathCaseHackMatchesNix (0.05s)18=== RUN TestDumpPathCaseHackCollision19--- PASS: TestDumpPathCaseHackCollision (0.00s)20=== RUN TestDumpPathMatchesNix21=== PAUSE TestDumpPathMatchesNix22=== RUN TestDumpPathSingleFile23=== PAUSE TestDumpPathSingleFile24=== RUN TestDumpPathWriterError25=== PAUSE TestDumpPathWriterError26=== RUN TestEncodeNixBase3227=== PAUSE TestEncodeNixBase3228=== RUN TestEncodeNixBase32WithRealHash29=== PAUSE TestEncodeNixBase32WithRealHash30=== RUN TestConvertHashToNix3231=== PAUSE TestConvertHashToNix3232=== RUN TestGetStorePathHash33=== PAUSE TestGetStorePathHash34=== RUN TestPathInfoHashCompatibility35=== PAUSE TestPathInfoHashCompatibility36=== RUN TestParsePathInfoJSON37=== PAUSE TestParsePathInfoJSON38=== RUN TestParsePathInfoJSONMultiplePaths39=== PAUSE TestParsePathInfoJSONMultiplePaths40=== RUN TestPathInfoCACompatibility41=== PAUSE TestPathInfoCACompatibility42=== RUN TestRateLimiterFeedback43=== PAUSE TestRateLimiterFeedback44=== RUN TestRateLimiterFeedback_400DoesNotCountAsSuccess45=== PAUSE TestRateLimiterFeedback_400DoesNotCountAsSuccess46=== RUN TestResolveStorePath47=== PAUSE TestResolveStorePath48=== RUN TestDoWithRetry_BodyReplayedViaGetBody49=== PAUSE TestDoWithRetry_BodyReplayedViaGetBody50=== RUN TestShellSplit51=== PAUSE TestShellSplit52=== RUN TestShellSplitErrors53=== PAUSE TestShellSplitErrors54=== RUN TestStreamPushReportsEveryPath55=== PAUSE TestStreamPushReportsEveryPath56=== RUN TestStreamPushBatchesUnderLoad57=== PAUSE TestStreamPushBatchesUnderLoad58=== RUN TestStreamPushIsolatesFailures59=== PAUSE TestStreamPushIsolatesFailures60=== RUN TestStreamPushGivesUpOnDeadServer61=== PAUSE TestStreamPushGivesUpOnDeadServer62=== RUN TestStreamPushRequestLine63=== PAUSE TestStreamPushRequestLine64=== RUN TestSetClientTLS65=== PAUSE TestSetClientTLS66=== RUN TestSetClientTLSDoesNotMutateDefaultTransport67=== PAUSE TestSetClientTLSDoesNotMutateDefaultTransport68=== RUN TestSetClientTLSErrors69=== PAUSE TestSetClientTLSErrors70=== RUN TestStaticToken71=== PAUSE TestStaticToken72=== RUN TestFileTokenReadsAndCaches73=== PAUSE TestFileTokenReadsAndCaches74=== RUN TestFileTokenMissing75=== PAUSE TestFileTokenMissing76=== RUN TestFileTokenEmpty77=== PAUSE TestFileTokenEmpty78=== RUN TestScriptTokenNoExpiryRerunsEveryCall79=== PAUSE TestScriptTokenNoExpiryRerunsEveryCall80=== RUN TestScriptTokenCachesUntilRefresh81=== PAUSE TestScriptTokenCachesUntilRefresh82=== RUN TestScriptTokenEmptyToken83=== PAUSE TestScriptTokenEmptyToken84=== RUN TestScriptTokenBadJSON85=== PAUSE TestScriptTokenBadJSON86=== RUN TestScriptTokenScriptFails87=== PAUSE TestScriptTokenScriptFails88=== RUN TestScriptTokenEmptyCommand89=== PAUSE TestScriptTokenEmptyCommand90=== CONT TestDoServerRequestAttachesToken91=== CONT TestStaticToken92--- PASS: TestStaticToken (0.00s)93=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess94=== CONT TestDoWithRetry_BodyReplayedViaGetBody95=== CONT TestStreamPushIsolatesFailures96=== CONT TestStreamPushBatchesUnderLoad97=== CONT TestStreamPushReportsEveryPath98=== CONT TestShellSplitErrors99--- PASS: TestShellSplitErrors (0.00s)100=== CONT TestRateLimiterFeedback101=== RUN TestRateLimiterFeedback/429_enables_limiter102=== PAUSE TestRateLimiterFeedback/429_enables_limiter103=== RUN TestRateLimiterFeedback/503_enables_limiter104=== PAUSE TestRateLimiterFeedback/503_enables_limiter105=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter106=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter107=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter108=== CONT TestShellSplit109=== CONT TestEncodeNixBase32WithRealHash110--- PASS: TestShellSplit (0.00s)111=== CONT TestPathInfoCACompatibility112--- PASS: TestEncodeNixBase32WithRealHash (0.00s)113=== CONT TestStreamPushGivesUpOnDeadServer114=== RUN TestPathInfoCACompatibility/null_ca_field115=== CONT TestResolveStorePath1162026/09/21 14:12:03 ERROR Upload failed error="bad path" count=31172026/09/21 14:12:03 WARN Rate limiter enabled after throttle name=server-test rate=5118=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter119=== PAUSE TestPathInfoCACompatibility/null_ca_field120=== RUN TestPathInfoCACompatibility/old_string_format_-_text121=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text122=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive123=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive124=== RUN TestPathInfoCACompatibility/new_structured_format_-_text125=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text126=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method127=== CONT TestParsePathInfoJSONMultiplePaths128=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method1292026/09/21 14:12:03 ERROR Upload failed error="connection refused" count=20130=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths131=== CONT TestParsePathInfoJSON1322026/09/21 14:12:03 ERROR Server seems unavailable, giving up on batch untried=17133=== RUN TestParsePathInfoJSON/Nix_format134--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)135=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths136=== CONT TestSetClientTLSErrors137--- PASS: TestStreamPushReportsEveryPath (0.00s)138=== CONT TestPathInfoHashCompatibility139--- PASS: TestStreamPushIsolatesFailures (0.00s)140=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)141=== CONT TestSetClientTLSDoesNotMutateDefaultTransport142=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)143=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon144=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon145=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI146=== PAUSE TestParsePathInfoJSON/Nix_format147=== RUN TestParsePathInfoJSON/Lix_format148=== PAUSE TestParsePathInfoJSON/Lix_format149=== RUN TestParsePathInfoJSON/empty_input150=== PAUSE TestParsePathInfoJSON/empty_input151=== RUN TestParsePathInfoJSON/whitespace_only152=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths153=== PAUSE TestParsePathInfoJSON/whitespace_only154=== RUN TestParsePathInfoJSON/invalid_JSON155=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths156=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI157=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512158=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512159=== CONT TestGetStorePathHash160=== RUN TestGetStorePathHash/valid_store_path161=== PAUSE TestGetStorePathHash/valid_store_path162=== RUN TestGetStorePathHash/basename_without_hyphen_should_error163=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error164=== PAUSE TestParsePathInfoJSON/invalid_JSON165=== CONT TestSetClientTLS166=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error167=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error168=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error169--- PASS: TestResolveStorePath (0.00s)170=== CONT TestStreamPushRequestLine171=== CONT TestConvertHashToNix321722026/09/21 14:12:03 WARN Rate limiter enabled after throttle name=server-test rate=51732026/09/21 14:12:03 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:61743174=== RUN TestConvertHashToNix32/SRI_format_to_Nix32175=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32176=== RUN TestConvertHashToNix32/already_Nix32_format177=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error178=== CONT TestScriptTokenCachesUntilRefresh179=== PAUSE TestConvertHashToNix32/already_Nix32_format180=== RUN TestConvertHashToNix32/invalid_format1812026/09/21 14:12:03 ERROR Upload failed error=boom count=1182=== PAUSE TestConvertHashToNix32/invalid_format183=== CONT TestFileTokenEmpty184--- PASS: TestDoServerRequestAttachesToken (0.00s)185=== CONT TestScriptTokenEmptyCommand186--- PASS: TestScriptTokenEmptyCommand (0.00s)187=== CONT TestScriptTokenNoExpiryRerunsEveryCall1882026/09/21 14:12:03 WARN Rate limiter backed off name=server-test rate=51892026/09/21 14:12:03 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:61743190--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.00s)191=== CONT TestScriptTokenScriptFails192=== RUN TestSetClientTLSErrors/missing_cert_file193--- PASS: TestFileTokenEmpty (0.00s)194=== PAUSE TestSetClientTLSErrors/missing_cert_file195=== RUN TestSetClientTLSErrors/missing_key_file196=== PAUSE TestSetClientTLSErrors/missing_key_file197=== RUN TestSetClientTLSErrors/missing_ca_file198=== PAUSE TestSetClientTLSErrors/missing_ca_file199=== RUN TestSetClientTLSErrors/invalid_ca_file200=== PAUSE TestSetClientTLSErrors/invalid_ca_file201=== CONT TestScriptTokenBadJSON202=== CONT TestUploadMultipart_SupersededByPeer203=== RUN TestUploadMultipart_SupersededByPeer/exists204=== PAUSE TestUploadMultipart_SupersededByPeer/exists205=== RUN TestUploadMultipart_SupersededByPeer/missing206=== PAUSE TestUploadMultipart_SupersededByPeer/missing207=== CONT TestEncodeNixBase32208=== RUN TestEncodeNixBase32/test_string_hash209=== PAUSE TestEncodeNixBase32/test_string_hash210=== RUN TestEncodeNixBase32/empty_input211--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.00s)212=== PAUSE TestEncodeNixBase32/empty_input213=== CONT TestScriptTokenEmptyToken214=== CONT TestDumpPathWriterError215=== RUN TestSetClientTLS/rejects_connection_without_client_cert216=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert217=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA218=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA219=== RUN TestSetClientTLS/preserves_debug_logging_transport220=== PAUSE TestSetClientTLS/preserves_debug_logging_transport221=== CONT TestDumpPathSingleFile222--- PASS: TestScriptTokenScriptFails (0.00s)223=== CONT TestDumpPathMatchesNix224--- PASS: TestScriptTokenEmptyToken (0.01s)225=== CONT TestFilterOversizedClosures226=== RUN TestFilterOversizedClosures/no_limit_keeps_everything227=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything228=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped229=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped230=== RUN TestFilterOversizedClosures/all_closures_skipped231=== PAUSE TestFilterOversizedClosures/all_closures_skipped232=== CONT TestCaseHackSuffix233--- PASS: TestScriptTokenBadJSON (0.01s)234=== CONT TestPartSizeForNAR235=== RUN TestPartSizeForNAR/zero_stays_at_minimum236=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum237=== RUN TestPartSizeForNAR/small_stays_at_minimum238=== PAUSE TestPartSizeForNAR/small_stays_at_minimum239=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum240=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum241=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts242=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts243=== RUN TestPartSizeForNAR/1_TiB244=== PAUSE TestPartSizeForNAR/1_TiB245=== RUN TestPartSizeForNAR/5_TiB_S3_max_object246=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object247=== RUN TestPartSizeForNAR/capped_at_5_GiB248=== PAUSE TestPartSizeForNAR/capped_at_5_GiB249=== CONT TestRegisterUploadedObjectReusesConnections250--- PASS: TestStreamPushRequestLine (0.02s)251=== CONT TestUploadMultipart_PartsInParallel252--- PASS: TestScriptTokenCachesUntilRefresh (0.03s)253=== CONT TestFileTokenMissing254--- PASS: TestFileTokenMissing (0.00s)255=== CONT TestFileTokenReadsAndCaches256--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.03s)257=== CONT TestRateLimiterFeedback/429_enables_limiter258--- PASS: TestFileTokenReadsAndCaches (0.00s)259=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter260=== CONT TestRateLimiterFeedback/503_enables_limiter2612026/09/21 14:12:04 WARN Rate limiter enabled after throttle name=server-test rate=52622026/09/21 14:12:04 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:618232632026/09/21 14:12:04 WARN Rate limiter backed off name=server-test rate=5264=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter2652026/09/21 14:12:04 WARN Rate limiter enabled after throttle name=server-test rate=52662026/09/21 14:12:04 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:618192672026/09/21 14:12:04 WARN Rate limiter backed off name=server-test rate=5268=== CONT TestPathInfoCACompatibility/null_ca_field269=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method270=== CONT TestPathInfoCACompatibility/old_string_format_-_text271=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive272=== CONT TestPathInfoCACompatibility/new_structured_format_-_text273--- PASS: TestPathInfoCACompatibility (0.00s)274 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)275 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)276 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)277 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)278 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)279=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths280=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths281--- PASS: TestParsePathInfoJSONMultiplePaths (0.00s)282 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)283 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)284=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)285=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512286=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI287=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon288--- PASS: TestPathInfoHashCompatibility (0.00s)289 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)290 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)291 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)292 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)293=== CONT TestParsePathInfoJSON/Nix_format294=== CONT TestParsePathInfoJSON/whitespace_only295=== CONT TestParsePathInfoJSON/empty_input296=== CONT TestParsePathInfoJSON/invalid_JSON297=== CONT TestParsePathInfoJSON/Lix_format298--- PASS: TestParsePathInfoJSON (0.00s)299 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)300 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)301 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)302 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)303 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)304=== CONT TestGetStorePathHash/valid_store_path305=== CONT TestConvertHashToNix32/SRI_format_to_Nix32306=== CONT TestConvertHashToNix32/invalid_format307=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error308=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error309=== CONT TestConvertHashToNix32/already_Nix32_format310--- PASS: TestConvertHashToNix32 (0.00s)311 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)312 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)313 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)314=== CONT TestGetStorePathHash/basename_without_hyphen_should_error315--- PASS: TestGetStorePathHash (0.00s)316 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)317 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)318 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)319 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)320=== CONT TestSetClientTLSErrors/missing_cert_file321=== CONT TestSetClientTLSErrors/missing_ca_file322=== CONT TestSetClientTLSErrors/invalid_ca_file323=== CONT TestSetClientTLSErrors/missing_key_file324--- PASS: TestRateLimiterFeedback (0.00s)325 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)326 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)327 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)328 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)329=== CONT TestUploadMultipart_SupersededByPeer/exists330=== CONT TestUploadMultipart_SupersededByPeer/missing331--- PASS: TestSetClientTLSErrors (0.00s)332 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)333 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)334 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)335 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)336=== CONT TestEncodeNixBase32/test_string_hash337=== CONT TestEncodeNixBase32/empty_input338--- PASS: TestEncodeNixBase32 (0.00s)339 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)340 --- PASS: TestEncodeNixBase32/empty_input (0.00s)341--- PASS: TestUploadMultipart_SupersededByPeer (0.00s)342 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)343 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)344=== CONT TestSetClientTLS/rejects_connection_without_client_cert345=== CONT TestSetClientTLS/preserves_debug_logging_transport346=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA347--- PASS: TestRegisterUploadedObjectReusesConnections (0.03s)348=== CONT TestFilterOversizedClosures/no_limit_keeps_everything349=== CONT TestFilterOversizedClosures/all_closures_skipped3502026/09/21 14:12:04 WARN Skipping closure: path exceeds server max NAR size top_level_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper oversized_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper nar_size=100 max_nar_size=50351=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped3522026/09/21 14:12:04 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=2000353--- PASS: TestFilterOversizedClosures (0.00s)354 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)355 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)356 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)357=== CONT TestPartSizeForNAR/zero_stays_at_minimum358=== CONT TestPartSizeForNAR/1_TiB359=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum360=== CONT TestPartSizeForNAR/capped_at_5_GiB361=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts362=== CONT TestPartSizeForNAR/5_TiB_S3_max_object363=== CONT TestPartSizeForNAR/small_stays_at_minimum364--- PASS: TestPartSizeForNAR (0.00s)365 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)366 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)367 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)368 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)369 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)370 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)371 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)372--- PASS: TestDumpPathWriterError (0.05s)3732026/09/21 14:12:04 http: TLS handshake error from 127.0.0.1:61832: remote error: tls: bad certificate374--- PASS: TestSetClientTLS (0.00s)375 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.00s)376 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.00s)377 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.01s)378--- PASS: TestDumpPathSingleFile (0.05s)379--- PASS: TestCaseHackSuffix (0.04s)380--- PASS: TestDumpPathMatchesNix (0.07s)381--- PASS: TestStreamPushBatchesUnderLoad (0.10s)382--- PASS: TestUploadMultipart_PartsInParallel (0.62s)383--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)384PASS385Running server tests...386The files belonging to this database system will be owned by user "_nixbld1".387This user must also own the server process.388389The database cluster will be initialized with locale "C".390The default database encoding has accordingly been set to "SQL_ASCII".391The default text search configuration will be set to "english".392393Data page checksums are enabled.394395creating directory /nix/var/nix/builds/nix-68162-1667843226/postgres3951945858/data ... ok396creating subdirectories ... ok397selecting dynamic shared memory implementation ... posix398selecting default "max_connections" ... 100399selecting default "shared_buffers" ... 128MB400selecting default time zone ... UTC401creating configuration files ... ok402running bootstrap script ... ok403performing post-bootstrap initialization ... ok404syncing data to disk ... ok405406initdb: warning: enabling "trust" authentication for local connections407initdb: 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.408409Success. You can now start the database server using:410411 pg_ctl -D /nix/var/nix/builds/nix-68162-1667843226/postgres3951945858/data -l logfile start412413/nix/var/nix/builds/nix-68162-1667843226/postgres3951945858:5432 - no response4142026-09-21 14:12:05.704 UTC [68203] LOG: starting PostgreSQL 18.6 on aarch64-apple-darwin25.6.0, compiled by clang version 21.1.8, 64-bit4152026-09-21 14:12:05.704 UTC [68203] LOG: listening on Unix socket "/nix/var/nix/builds/nix-68162-1667843226/postgres3951945858/.s.PGSQL.5432"4162026-09-21 14:12:05.706 UTC [68210] LOG: database system was shut down at 2026-09-21 14:12:05 UTC4172026-09-21 14:12:05.707 UTC [68203] LOG: database system is ready to accept connections418/nix/var/nix/builds/nix-68162-1667843226/postgres3951945858:5432 - accepting connections419{"timestamp":"2026-09-21T14:12:05.922911Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"f27cefe0-071a-4843-abef-e6e723d4358c","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"GET","uri":"/health/ready","status_code":503,"duration_ms":0,"result":"server_error","target":"rustfs::server::http","filename":"rustfs/src/server/layer.rs","line_number":430,"threadName":"rustfs-worker","threadId":"ThreadId(11)"}420=== RUN TestService_AuthMiddleware421=== PAUSE TestService_AuthMiddleware422=== RUN TestService_AuthMiddleware_MTLSProxyHeader423=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader424=== RUN TestService_AuthMiddleware_MTLSBoundSubjects425=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects426=== RUN TestService_ReadAuthMiddleware427=== PAUSE TestService_ReadAuthMiddleware428=== RUN TestService_AuthMiddleware_OIDC429=== PAUSE TestService_AuthMiddleware_OIDC430=== RUN TestService_RequireScope_OIDC431=== PAUSE TestService_RequireScope_OIDC432=== RUN TestService_ReadScope_PublicByDefault433=== PAUSE TestService_ReadScope_PublicByDefault434=== RUN TestCacheConfigHandler435=== PAUSE TestCacheConfigHandler436=== RUN TestCacheStatsHandler437=== PAUSE TestCacheStatsHandler438=== RUN TestClientCADerivations439=== PAUSE TestClientCADerivations440=== RUN TestClientErrorHandling441=== PAUSE TestClientErrorHandling442=== RUN TestClientIntegration443=== PAUSE TestClientIntegration444=== RUN TestClientMultipleUploads445=== PAUSE TestClientMultipleUploads446=== RUN TestClientWithDependencies447=== PAUSE TestClientWithDependencies448=== RUN TestClientSharedPathCommittedMidPush449=== PAUSE TestClientSharedPathCommittedMidPush450=== RUN TestPinProtectsFromGC451=== PAUSE TestPinProtectsFromGC452=== RUN TestResolveDBConnectionString453=== PAUSE TestResolveDBConnectionString454=== RUN TestLeadElectsOneAndHandsOver455=== PAUSE TestLeadElectsOneAndHandsOver456=== RUN TestLeadIncumbentWinsAfterRestart4572026-09-21 14:12:06.177 UTC [68282] ERROR: relation "goose_db_version" does not exist at character 364582026-09-21 14:12:06.177 UTC [68282] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC4592026/09/21 14:12:06 OK 20241026095416_initial_model.sql (4.17ms)4602026/09/21 14:12:06 OK 20251210153512_drop_unused_gin_index.sql (565.88µs)4612026/09/21 14:12:06 OK 20251218171726_add_pins.sql (983.17µs)4622026/09/21 14:12:06 OK 20260628120000_add_object_size_and_stats.sql (1.01ms)4632026/09/21 14:12:06 OK 20260905000000_add_claims.sql (1.11ms)4642026/09/21 14:12:06 OK 20260920000000_drop_claims.sql (673.96µs)4652026/09/21 14:12:06 goose: successfully migrated database to version: 202609200000004662026/09/21 14:12:06 OK 1_commit_pending_closure.sql (946.08µs)4672026/09/21 14:12:06 OK 2_object_stats_trigger.sql (219.63µs)4682026/09/21 14:12:06 goose: up to current file version: 24692026/09/21 14:12:06 INFO lead: acquired remote=192.0.2.1:12344702026/09/21 14:12:06 INFO lead: released remote=192.0.2.1:12344712026/09/21 14:12:06 INFO lead: acquired remote=192.0.2.1:12344722026/09/21 14:12:06 INFO lead: released remote=192.0.2.1:1234473--- PASS: TestLeadIncumbentWinsAfterRestart (0.88s)474=== RUN TestLeadEndsOnShutdown475=== PAUSE TestLeadEndsOnShutdown476=== RUN TestGCAdvisoryLockBlocksConcurrentRun4772026-09-21 14:12:06.990 UTC [68286] ERROR: relation "goose_db_version" does not exist at character 364782026-09-21 14:12:06.990 UTC [68286] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC4792026/09/21 14:12:06 OK 20241026095416_initial_model.sql (3.62ms)4802026/09/21 14:12:06 OK 20251210153512_drop_unused_gin_index.sql (369.58µs)4812026/09/21 14:12:06 OK 20251218171726_add_pins.sql (856.79µs)4822026/09/21 14:12:06 OK 20260628120000_add_object_size_and_stats.sql (970.25µs)4832026/09/21 14:12:06 OK 20260905000000_add_claims.sql (998.38µs)4842026/09/21 14:12:07 OK 20260920000000_drop_claims.sql (637µs)4852026/09/21 14:12:07 goose: successfully migrated database to version: 202609200000004862026/09/21 14:12:07 OK 1_commit_pending_closure.sql (882.04µs)4872026/09/21 14:12:07 OK 2_object_stats_trigger.sql (229.79µs)4882026/09/21 14:12:07 goose: up to current file version: 2489--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.16s)490=== RUN TestGCBugBareHashReferences491=== PAUSE TestGCBugBareHashReferences492=== RUN TestGCMetrics493=== PAUSE TestGCMetrics494=== RUN TestGCTaskStore_StartNew495=== PAUSE TestGCTaskStore_StartNew496=== RUN TestGCTaskStore_DeduplicateSameParams497=== PAUSE TestGCTaskStore_DeduplicateSameParams498=== RUN TestGCTaskStore_ConflictDifferentParams499=== PAUSE TestGCTaskStore_ConflictDifferentParams500=== RUN TestGCTaskStore_GetEmpty501=== PAUSE TestGCTaskStore_GetEmpty502=== RUN TestGCTaskStore_GetReturnsLatest503=== PAUSE TestGCTaskStore_GetReturnsLatest504=== RUN TestGCTaskStore_CompletedAllowsNewTask505=== PAUSE TestGCTaskStore_CompletedAllowsNewTask506=== RUN TestGCTaskStore_PhaseUpdates507=== PAUSE TestGCTaskStore_PhaseUpdates508=== RUN TestGCTaskStore_Fail509=== PAUSE TestGCTaskStore_Fail510=== RUN TestGracefulShutdownDrainsInflight511=== PAUSE TestGracefulShutdownDrainsInflight512=== RUN TestService_healthCheckHandler513=== PAUSE TestService_healthCheckHandler514=== RUN TestService_readinessHandler515=== PAUSE TestService_readinessHandler516=== RUN TestGenerateLandingPage517=== PAUSE TestGenerateLandingPage518=== RUN TestCacheConfigHandlerMaxNarSize519=== PAUSE TestCacheConfigHandlerMaxNarSize520=== RUN TestCreatePendingClosureRejectsOversizedNAR521=== PAUSE TestCreatePendingClosureRejectsOversizedNAR522=== RUN TestNARDeduplicationMetadataUploadBug523=== PAUSE TestNARDeduplicationMetadataUploadBug524=== RUN TestMetricsInventory525=== PAUSE TestMetricsInventory526=== RUN TestService_NativeMTLS527=== PAUSE TestService_NativeMTLS528=== RUN TestServerTLSConfig529=== PAUSE TestServerTLSConfig530=== RUN TestMultipartCleanup531=== PAUSE TestMultipartCleanup532=== RUN TestObjectStatsTrigger533=== PAUSE TestObjectStatsTrigger534=== RUN TestOrphanedObjectsGC535=== PAUSE TestOrphanedObjectsGC536=== RUN TestOrphanedObjectsGCStressTest537=== PAUSE TestOrphanedObjectsGCStressTest538=== RUN TestResurrectedObjectNotDeleted539=== PAUSE TestResurrectedObjectNotDeleted540=== RUN TestParseSingleRange541=== PAUSE TestParseSingleRange542=== RUN TestIsValidCachePath543=== PAUSE TestIsValidCachePath544=== RUN TestReadProxyNarinfo545=== PAUSE TestReadProxyNarinfo546=== RUN TestReadProxyNarinfoAlreadyDecompressed547=== PAUSE TestReadProxyNarinfoAlreadyDecompressed548=== RUN TestReadProxyNarStreaming549=== PAUSE TestReadProxyNarStreaming550=== RUN TestReadProxy404551=== PAUSE TestReadProxy404552=== RUN TestReadProxyInvalidPath553=== PAUSE TestReadProxyInvalidPath554=== RUN TestReadProxyHead555=== PAUSE TestReadProxyHead556=== RUN TestReadProxyConditionalGet557=== PAUSE TestReadProxyConditionalGet558=== RUN TestReadProxyRootRedirectsToIndexHTML559=== PAUSE TestReadProxyRootRedirectsToIndexHTML560=== RUN TestReadProxyDisabled561=== PAUSE TestReadProxyDisabled562=== RUN TestReadRedirectNar563=== PAUSE TestReadRedirectNar564=== RUN TestReadRedirectKeepsNarinfoProxied565=== PAUSE TestReadRedirectKeepsNarinfoProxied566=== RUN TestReadProxyRangeRequest567=== PAUSE TestReadProxyRangeRequest568=== RUN TestReadRedirectUsesPublicS3URL569=== PAUSE TestReadRedirectUsesPublicS3URL570=== RUN TestRedundantMultipartUpload571=== PAUSE TestRedundantMultipartUpload572=== RUN TestCompleteMultipartUpload_ErrorButObjectExists573=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists574=== RUN TestCompletedNarNotReofferedAcrossClosures575=== PAUSE TestCompletedNarNotReofferedAcrossClosures576=== RUN TestPresignedUploadRegisteredBeforeCommit577=== PAUSE TestPresignedUploadRegisteredBeforeCommit578=== RUN TestService_Rustfstest579=== PAUSE TestService_Rustfstest580=== RUN TestParseSize581=== PAUSE TestParseSize582=== RUN TestSkippedUploadsHandler583=== PAUSE TestSkippedUploadsHandler584=== RUN TestSystemdListenerNotActivated585--- PASS: TestSystemdListenerNotActivated (0.00s)586=== RUN TestWatchdogBeatsWhenHealthy587--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)588=== RUN TestWatchdogSkipsWhenUnhealthy5892026/09/21 14:12:07 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5902026/09/21 14:12:07 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5912026/09/21 14:12:07 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5922026/09/21 14:12:07 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5932026/09/21 14:12:07 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5942026/09/21 14:12:07 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5952026/09/21 14:12:07 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5962026/09/21 14:12:07 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5972026/09/21 14:12:07 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5982026/09/21 14:12:07 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"599--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)600=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle601=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle602=== RUN TestProxyWriteTimeout603=== PAUSE TestProxyWriteTimeout604=== RUN TestIsValidUploadKey605=== PAUSE TestIsValidUploadKey606=== RUN TestUploadHandlersRejectInvalidKeys607=== PAUSE TestUploadHandlersRejectInvalidKeys608=== RUN TestUploadHandlersRejectOversizedBody609=== PAUSE TestUploadHandlersRejectOversizedBody610=== RUN TestService_cleanupPendingClosuresHandler611=== PAUSE TestService_cleanupPendingClosuresHandler612=== RUN TestService_createPendingClosureHandler613=== PAUSE TestService_createPendingClosureHandler614=== RUN TestService_verifyS3Integrity615=== PAUSE TestService_verifyS3Integrity616=== RUN TestCompleteMultipartUnregistered617=== PAUSE TestCompleteMultipartUnregistered618=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT619=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT620=== CONT TestService_AuthMiddleware621=== CONT TestCompletedNarNotReofferedAcrossClosures622=== CONT TestUploadHandlersRejectInvalidKeys623=== CONT TestService_verifyS3Integrity624=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info625=== CONT TestService_createPendingClosureHandler626=== CONT TestService_cleanupPendingClosuresHandler627=== CONT TestUploadHandlersRejectOversizedBody628=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT629=== CONT TestSkippedUploadsHandler630=== CONT TestIsValidUploadKey631=== RUN TestIsValidUploadKey/narinfo632=== PAUSE TestIsValidUploadKey/narinfo633=== RUN TestIsValidUploadKey/nar_zst634=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info635=== PAUSE TestIsValidUploadKey/nar_zst636=== RUN TestIsValidUploadKey/nar_xz637=== PAUSE TestIsValidUploadKey/nar_xz638=== RUN TestIsValidUploadKey/nar_plain639=== PAUSE TestIsValidUploadKey/nar_plain640=== RUN TestIsValidUploadKey/listing641=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal6422026/09/21 14:12:07 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000643=== PAUSE TestIsValidUploadKey/listing644=== RUN TestIsValidUploadKey/build_log645=== PAUSE TestIsValidUploadKey/build_log646=== RUN TestIsValidUploadKey/build_log_home-manager_file647=== PAUSE TestIsValidUploadKey/build_log_home-manager_file648=== RUN TestIsValidUploadKey/build_log_plus_in_name649=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal650=== PAUSE TestIsValidUploadKey/build_log_plus_in_name651=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key652=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key653=== RUN TestIsValidUploadKey/build_log_question_mark654=== PAUSE TestIsValidUploadKey/build_log_question_mark655=== RUN TestIsValidUploadKey/build_log_equals656=== PAUSE TestIsValidUploadKey/build_log_equals657=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key658=== RUN TestIsValidUploadKey/realisation659=== PAUSE TestIsValidUploadKey/realisation660=== RUN TestIsValidUploadKey/realisation_plus_in_output661=== PAUSE TestIsValidUploadKey/realisation_plus_in_output662=== RUN TestIsValidUploadKey/nix-cache-info663=== PAUSE TestIsValidUploadKey/nix-cache-info664=== RUN TestIsValidUploadKey/index.html665=== PAUSE TestIsValidUploadKey/index.html666=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key667=== RUN TestIsValidUploadKey/narinfo_key,_nar_type668=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type669=== RUN TestIsValidUploadKey/nar_key,_narinfo_type670=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type671=== RUN TestIsValidUploadKey/listing_key,_narinfo_type672=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle673=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type674--- PASS: TestSkippedUploadsHandler (0.04s)675=== CONT TestProxyWriteTimeout676=== RUN TestProxyWriteTimeout/narinfo677=== PAUSE TestProxyWriteTimeout/narinfo678=== RUN TestIsValidUploadKey/traversal679=== PAUSE TestIsValidUploadKey/traversal680=== RUN TestIsValidUploadKey/traversal_nar681=== PAUSE TestIsValidUploadKey/traversal_nar682=== RUN TestIsValidUploadKey/absolute683=== PAUSE TestIsValidUploadKey/absolute684=== RUN TestIsValidUploadKey/empty_key685=== PAUSE TestIsValidUploadKey/empty_key686=== RUN TestIsValidUploadKey/unknown_type687=== PAUSE TestIsValidUploadKey/unknown_type688=== RUN TestProxyWriteTimeout/1_GiB_nar689=== CONT TestCompleteMultipartUnregistered690=== PAUSE TestProxyWriteTimeout/1_GiB_nar691=== RUN TestProxyWriteTimeout/10_GiB_nar692=== PAUSE TestProxyWriteTimeout/10_GiB_nar693=== RUN TestProxyWriteTimeout/unknown_size694=== PAUSE TestProxyWriteTimeout/unknown_size695=== CONT TestService_Rustfstest696=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure697=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure698=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart699=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart700=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts701=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts702=== CONT TestParseSize703--- PASS: TestParseSize (0.00s)704=== CONT TestPresignedUploadRegisteredBeforeCommit7052026-09-21 14:12:07.588 UTC [68308] ERROR: relation "goose_db_version" does not exist at character 367062026-09-21 14:12:07.588 UTC [68308] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7072026-09-21 14:12:07.590 UTC [68309] ERROR: relation "goose_db_version" does not exist at character 367082026-09-21 14:12:07.590 UTC [68309] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7092026-09-21 14:12:07.590 UTC [68310] ERROR: relation "goose_db_version" does not exist at character 367102026-09-21 14:12:07.590 UTC [68310] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7112026-09-21 14:12:07.594 UTC [68311] ERROR: relation "goose_db_version" does not exist at character 367122026-09-21 14:12:07.594 UTC [68311] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7132026-09-21 14:12:07.595 UTC [68312] ERROR: relation "goose_db_version" does not exist at character 367142026-09-21 14:12:07.595 UTC [68312] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7152026-09-21 14:12:07.595 UTC [68313] ERROR: relation "goose_db_version" does not exist at character 367162026-09-21 14:12:07.595 UTC [68313] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7172026-09-21 14:12:07.601 UTC [68314] ERROR: relation "goose_db_version" does not exist at character 367182026-09-21 14:12:07.601 UTC [68314] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7192026-09-21 14:12:07.602 UTC [68315] ERROR: relation "goose_db_version" does not exist at character 367202026-09-21 14:12:07.602 UTC [68315] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7212026-09-21 14:12:07.602 UTC [68316] ERROR: relation "goose_db_version" does not exist at character 367222026-09-21 14:12:07.602 UTC [68316] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7232026-09-21 14:12:07.603 UTC [68317] ERROR: relation "goose_db_version" does not exist at character 367242026-09-21 14:12:07.603 UTC [68317] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7252026/09/21 14:12:07 OK 20241026095416_initial_model.sql (8.95ms)7262026/09/21 14:12:07 OK 20241026095416_initial_model.sql (8.52ms)7272026/09/21 14:12:07 OK 20251210153512_drop_unused_gin_index.sql (854.67µs)7282026/09/21 14:12:07 OK 20251210153512_drop_unused_gin_index.sql (689.25µs)7292026/09/21 14:12:07 OK 20241026095416_initial_model.sql (7.25ms)7302026/09/21 14:12:07 OK 20241026095416_initial_model.sql (9.22ms)7312026/09/21 14:12:07 OK 20251218171726_add_pins.sql (1.47ms)7322026/09/21 14:12:07 OK 20241026095416_initial_model.sql (7.73ms)7332026/09/21 14:12:07 OK 20251218171726_add_pins.sql (1.76ms)7342026/09/21 14:12:07 OK 20251210153512_drop_unused_gin_index.sql (956.83µs)7352026/09/21 14:12:07 OK 20251210153512_drop_unused_gin_index.sql (1.25ms)7362026/09/21 14:12:07 OK 20241026095416_initial_model.sql (8.59ms)7372026/09/21 14:12:07 OK 20251210153512_drop_unused_gin_index.sql (1.3ms)7382026/09/21 14:12:07 OK 20260628120000_add_object_size_and_stats.sql (1.49ms)7392026/09/21 14:12:07 OK 20260628120000_add_object_size_and_stats.sql (1.79ms)7402026/09/21 14:12:07 OK 20251210153512_drop_unused_gin_index.sql (936.17µs)7412026/09/21 14:12:07 OK 20251218171726_add_pins.sql (1.82ms)7422026/09/21 14:12:07 OK 20251218171726_add_pins.sql (2.48ms)7432026/09/21 14:12:07 OK 20260905000000_add_claims.sql (2.34ms)7442026/09/21 14:12:07 OK 20251218171726_add_pins.sql (2.79ms)7452026/09/21 14:12:07 OK 20251218171726_add_pins.sql (2.02ms)7462026/09/21 14:12:07 OK 20260628120000_add_object_size_and_stats.sql (1.87ms)7472026/09/21 14:12:07 OK 20260905000000_add_claims.sql (2.45ms)7482026/09/21 14:12:07 OK 20260628120000_add_object_size_and_stats.sql (1.87ms)7492026/09/21 14:12:07 OK 20260920000000_drop_claims.sql (1.33ms)7502026/09/21 14:12:07 goose: successfully migrated database to version: 202609200000007512026/09/21 14:12:07 OK 20260920000000_drop_claims.sql (1.69ms)7522026/09/21 14:12:07 goose: successfully migrated database to version: 202609200000007532026/09/21 14:12:07 OK 20260905000000_add_claims.sql (1.88ms)7542026/09/21 14:12:07 OK 20260628120000_add_object_size_and_stats.sql (2.47ms)7552026/09/21 14:12:07 OK 20260628120000_add_object_size_and_stats.sql (2.37ms)7562026/09/21 14:12:07 OK 1_commit_pending_closure.sql (1.92ms)7572026/09/21 14:12:07 OK 20260905000000_add_claims.sql (2.45ms)7582026/09/21 14:12:07 OK 1_commit_pending_closure.sql (1.05ms)7592026/09/21 14:12:07 OK 2_object_stats_trigger.sql (488.33µs)7602026/09/21 14:12:07 goose: up to current file version: 27612026/09/21 14:12:07 OK 20241026095416_initial_model.sql (8.04ms)7622026/09/21 14:12:07 OK 20241026095416_initial_model.sql (8.79ms)7632026/09/21 14:12:07 OK 20241026095416_initial_model.sql (7.09ms)7642026/09/21 14:12:07 OK 2_object_stats_trigger.sql (671.75µs)7652026/09/21 14:12:07 goose: up to current file version: 27662026/09/21 14:12:07 OK 20241026095416_initial_model.sql (7.65ms)7672026/09/21 14:12:07 OK 20260920000000_drop_claims.sql (1.68ms)7682026/09/21 14:12:07 goose: successfully migrated database to version: 202609200000007692026/09/21 14:12:07 OK 20251210153512_drop_unused_gin_index.sql (414.46µs)7702026/09/21 14:12:07 OK 20260905000000_add_claims.sql (2.18ms)7712026/09/21 14:12:07 OK 20260920000000_drop_claims.sql (1.63ms)7722026/09/21 14:12:07 goose: successfully migrated database to version: 202609200000007732026/09/21 14:12:07 OK 20251210153512_drop_unused_gin_index.sql (699.88µs)7742026/09/21 14:12:07 OK 20260905000000_add_claims.sql (2.69ms)7752026/09/21 14:12:07 OK 1_commit_pending_closure.sql (1.15ms)7762026/09/21 14:12:07 OK 20251210153512_drop_unused_gin_index.sql (756.54µs)7772026/09/21 14:12:07 OK 20251210153512_drop_unused_gin_index.sql (741.5µs)7782026/09/21 14:12:07 OK 2_object_stats_trigger.sql (525.5µs)7792026/09/21 14:12:07 goose: up to current file version: 27802026/09/21 14:12:07 OK 20251218171726_add_pins.sql (1.17ms)7812026/09/21 14:12:07 OK 1_commit_pending_closure.sql (1.21ms)7822026/09/21 14:12:07 OK 20260920000000_drop_claims.sql (873.96µs)7832026/09/21 14:12:07 goose: successfully migrated database to version: 202609200000007842026/09/21 14:12:07 OK 2_object_stats_trigger.sql (240.29µs)7852026/09/21 14:12:07 goose: up to current file version: 27862026/09/21 14:12:07 OK 1_commit_pending_closure.sql (781.67µs)7872026/09/21 14:12:07 OK 2_object_stats_trigger.sql (209.29µs)7882026/09/21 14:12:07 goose: up to current file version: 27892026/09/21 14:12:07 OK 20260920000000_drop_claims.sql (13.81ms)7902026/09/21 14:12:07 goose: successfully migrated database to version: 202609200000007912026/09/21 14:12:07 OK 20251218171726_add_pins.sql (13.94ms)7922026/09/21 14:12:07 OK 20251218171726_add_pins.sql (14.17ms)7932026/09/21 14:12:07 OK 1_commit_pending_closure.sql (862.17µs)7942026/09/21 14:12:07 OK 20251218171726_add_pins.sql (14.12ms)7952026/09/21 14:12:07 OK 20260628120000_add_object_size_and_stats.sql (13.86ms)7962026/09/21 14:12:07 OK 2_object_stats_trigger.sql (331.38µs)7972026/09/21 14:12:07 goose: up to current file version: 27982026/09/21 14:12:07 OK 20260628120000_add_object_size_and_stats.sql (9.47ms)7992026/09/21 14:12:07 OK 20260628120000_add_object_size_and_stats.sql (9.51ms)8002026/09/21 14:12:07 OK 20260628120000_add_object_size_and_stats.sql (14.56ms)8012026/09/21 14:12:07 OK 20260905000000_add_claims.sql (15.2ms)8022026/09/21 14:12:07 OK 20260905000000_add_claims.sql (13.29ms)8032026/09/21 14:12:07 OK 20260905000000_add_claims.sql (13.39ms)8042026/09/21 14:12:07 OK 20260920000000_drop_claims.sql (10.93ms)8052026/09/21 14:12:07 goose: successfully migrated database to version: 202609200000008062026/09/21 14:12:07 OK 20260905000000_add_claims.sql (12.04ms)8072026/09/21 14:12:07 OK 1_commit_pending_closure.sql (672.46µs)8082026/09/21 14:12:07 OK 2_object_stats_trigger.sql (164.96µs)8092026/09/21 14:12:07 goose: up to current file version: 28102026/09/21 14:12:07 OK 20260920000000_drop_claims.sql (8.61ms)8112026/09/21 14:12:07 goose: successfully migrated database to version: 202609200000008122026/09/21 14:12:07 OK 1_commit_pending_closure.sql (750.5µs)8132026/09/21 14:12:07 OK 20260920000000_drop_claims.sql (9.38ms)8142026/09/21 14:12:07 goose: successfully migrated database to version: 202609200000008152026/09/21 14:12:07 OK 2_object_stats_trigger.sql (199.42µs)8162026/09/21 14:12:07 goose: up to current file version: 28172026/09/21 14:12:07 OK 20260920000000_drop_claims.sql (5.61ms)8182026/09/21 14:12:07 goose: successfully migrated database to version: 202609200000008192026/09/21 14:12:07 OK 1_commit_pending_closure.sql (715.13µs)8202026/09/21 14:12:07 OK 1_commit_pending_closure.sql (667.25µs)8212026/09/21 14:12:07 OK 2_object_stats_trigger.sql (208.96µs)8222026/09/21 14:12:07 goose: up to current file version: 28232026/09/21 14:12:07 OK 2_object_stats_trigger.sql (159.17µs)8242026/09/21 14:12:07 goose: up to current file version: 28252026/09/21 14:12:07 INFO Received uploads request method=POST path=/api/pending_closures8262026/09/21 14:12:07 INFO Received uploads request method=POST path=/api/pending_closures8272026/09/21 14:12:07 INFO Received uploads request method=POST path=/api/pending_closures8282026/09/21 14:12:07 INFO Received uploads request method=POST path=/api/pending_closures8292026/09/21 14:12:08 INFO Received cleanup request method=DELETE path=/api/pending_closures8302026/09/21 14:12:08 INFO Aborted multipart uploads count=08312026/09/21 14:12:08 INFO Received uploads request method=POST path=/api/pending_closures8322026/09/21 14:12:08 INFO Received cleanup request method=DELETE path=/api/pending_closures8332026/09/21 14:12:08 INFO Aborted multipart uploads count=18342026/09/21 14:12:08 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete8352026-09-21 14:12:08.120 UTC [68309] ERROR: Closure does not exist: id=18362026-09-21 14:12:08.120 UTC [68309] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 16 at RAISE8372026-09-21 14:12:08.120 UTC [68309] STATEMENT: -- name: CommitPendingClosure :exec838 SELECT commit_pending_closure($1::bigint)839 840--- PASS: TestService_cleanupPendingClosuresHandler (0.83s)841=== CONT TestService_readinessHandler8422026/09/21 14:12:08 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"843--- PASS: TestService_AuthMiddleware (0.99s)844=== CONT TestCompleteMultipartUpload_ErrorButObjectExists8452026/09/21 14:12:08 INFO Received uploads request method=POST path=/api/pending_closures8462026/09/21 14:12:08 INFO Received uploads request method=POST path=/api/pending_closures847--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (1.53s)848=== CONT TestIsValidCachePath849=== RUN TestIsValidCachePath/narinfo850=== PAUSE TestIsValidCachePath/narinfo851=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars852=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars853=== RUN TestIsValidCachePath/nar_zst854=== PAUSE TestIsValidCachePath/nar_zst855=== RUN TestIsValidCachePath/nar_xz856=== PAUSE TestIsValidCachePath/nar_xz857=== RUN TestIsValidCachePath/nar_bz2858=== PAUSE TestIsValidCachePath/nar_bz2859=== RUN TestIsValidCachePath/nar_uncompressed860=== PAUSE TestIsValidCachePath/nar_uncompressed861=== RUN TestIsValidCachePath/ls862=== PAUSE TestIsValidCachePath/ls863=== RUN TestIsValidCachePath/log864=== PAUSE TestIsValidCachePath/log865=== RUN TestIsValidCachePath/realisation866=== PAUSE TestIsValidCachePath/realisation867=== RUN TestIsValidCachePath/nix-cache-info868=== PAUSE TestIsValidCachePath/nix-cache-info869=== RUN TestIsValidCachePath/index.html870=== PAUSE TestIsValidCachePath/index.html871=== RUN TestIsValidCachePath/traversal_parent872=== PAUSE TestIsValidCachePath/traversal_parent873=== RUN TestIsValidCachePath/traversal_in_middle874=== PAUSE TestIsValidCachePath/traversal_in_middle875=== RUN TestIsValidCachePath/invalid_char_e876=== PAUSE TestIsValidCachePath/invalid_char_e877=== RUN TestIsValidCachePath/invalid_char_u878=== PAUSE TestIsValidCachePath/invalid_char_u879=== RUN TestIsValidCachePath/random_path880=== PAUSE TestIsValidCachePath/random_path881=== RUN TestIsValidCachePath/empty882=== PAUSE TestIsValidCachePath/empty883=== RUN TestIsValidCachePath/leading_slash884=== PAUSE TestIsValidCachePath/leading_slash885=== RUN TestIsValidCachePath/wrong_extension886=== PAUSE TestIsValidCachePath/wrong_extension887=== RUN TestIsValidCachePath/short_hash888=== PAUSE TestIsValidCachePath/short_hash889=== CONT TestParseSingleRange890=== RUN TestParseSingleRange/none891=== PAUSE TestParseSingleRange/none892=== RUN TestParseSingleRange/unknown_unit893=== PAUSE TestParseSingleRange/unknown_unit894=== RUN TestParseSingleRange/multi-range_ignored895=== PAUSE TestParseSingleRange/multi-range_ignored896=== RUN TestParseSingleRange/malformed_no_dash897=== PAUSE TestParseSingleRange/malformed_no_dash898=== RUN TestParseSingleRange/malformed_both_empty899=== PAUSE TestParseSingleRange/malformed_both_empty900=== RUN TestParseSingleRange/malformed_end_before_start901=== PAUSE TestParseSingleRange/malformed_end_before_start902=== RUN TestParseSingleRange/closed903=== PAUSE TestParseSingleRange/closed904=== RUN TestParseSingleRange/open-ended905=== PAUSE TestParseSingleRange/open-ended906=== RUN TestParseSingleRange/end_clamped_to_size907=== PAUSE TestParseSingleRange/end_clamped_to_size908=== RUN TestParseSingleRange/suffix909=== PAUSE TestParseSingleRange/suffix910=== RUN TestParseSingleRange/suffix_exceeds_size911=== PAUSE TestParseSingleRange/suffix_exceeds_size912=== RUN TestParseSingleRange/single_byte913=== PAUSE TestParseSingleRange/single_byte914=== RUN TestParseSingleRange/start_past_EOF915=== PAUSE TestParseSingleRange/start_past_EOF916=== RUN TestParseSingleRange/start_far_past_EOF917=== PAUSE TestParseSingleRange/start_far_past_EOF918=== CONT TestResurrectedObjectNotDeleted9192026/09/21 14:12:08 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9202026/09/21 14:12:08 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=MmI5ZWFhNjktZDkzNy00ZTdhLWI1ZWEtOGY1YzQ4YjQ5NjA2LmI1Y2RlZjYzLTk0NTUtNDUzNS05ZjE0LTE1NGMwYWUzNThmM3gxNzg5OTk5OTI3NzAyOTcwMDAw parts=109212026/09/21 14:12:08 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete9222026/09/21 14:12:08 INFO Completed upload id=19232026/09/21 14:12:08 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000009242026/09/21 14:12:08 INFO Received uploads request method=POST path=/api/pending_closures9252026/09/21 14:12:08 INFO Starting cleanup of old closures method=DELETE path=/api/closures9262026/09/21 14:12:08 INFO Aborted multipart uploads count=09272026/09/21 14:12:08 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=2 objects-deleted-after-grace-period=0 objects-failed-to-delete=09282026/09/21 14:12:08 INFO Vacuumed table table=pending_closures9292026/09/21 14:12:08 INFO Vacuumed table table=pending_objects9302026/09/21 14:12:08 INFO Vacuumed table table=multipart_uploads9312026/09/21 14:12:08 INFO Vacuumed table table=closures9322026/09/21 14:12:09 INFO Vacuumed table table=objects9332026/09/21 14:12:09 INFO Received uploads request method=POST path=/api/pending_closures9342026/09/21 14:12:09 INFO Received get closure request method=GET path=/api/closures/00000000000000000000000000000000935--- PASS: TestService_createPendingClosureHandler (1.76s)936=== CONT TestOrphanedObjectsGCStressTest9372026/09/21 14:12:09 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9382026/09/21 14:12:09 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst9392026/09/21 14:12:09 INFO Received uploads request method=POST path=/api/pending_closures940--- PASS: TestPresignedUploadRegisteredBeforeCommit (1.73s)941=== CONT TestOrphanedObjectsGC9422026/09/21 14:12:09 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=MmI5ZWFhNjktZDkzNy00ZTdhLWI1ZWEtOGY1YzQ4YjQ5NjA2LmViYjM5MTM2LTE2NWMtNDEzMi1iNWE2LWZlY2FiMWU3MDRhOHgxNzg5OTk5OTI3ODczMDUyMDAw parts=109432026/09/21 14:12:09 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete9442026/09/21 14:12:09 INFO Completed upload id=19452026/09/21 14:12:09 INFO Received uploads request method=POST path=/api/pending_closures9462026/09/21 14:12:09 INFO Received uploads request method=POST path=/api/pending_closures9472026/09/21 14:12:09 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo9482026/09/21 14:12:09 WARN Found objects in DB but missing from S3, will re-upload count=1949--- PASS: TestService_verifyS3Integrity (1.85s)950=== CONT TestObjectStatsTrigger9512026-09-21 14:12:09.209 UTC [68335] ERROR: relation "goose_db_version" does not exist at character 369522026-09-21 14:12:09.209 UTC [68335] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9532026/09/21 14:12:09 INFO Received uploads request method=POST path=/api/pending_closures9542026/09/21 14:12:09 OK 20241026095416_initial_model.sql (130.79ms)9552026/09/21 14:12:09 OK 20251210153512_drop_unused_gin_index.sql (20.63ms)9562026/09/21 14:12:09 OK 20251218171726_add_pins.sql (17.57ms)9572026/09/21 14:12:09 OK 20260628120000_add_object_size_and_stats.sql (36.1ms)958--- PASS: TestService_Rustfstest (2.16s)959=== CONT TestMultipartCleanup9602026/09/21 14:12:09 OK 20260905000000_add_claims.sql (47.03ms)9612026/09/21 14:12:09 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9622026/09/21 14:12:09 OK 20260920000000_drop_claims.sql (57.34ms)9632026/09/21 14:12:09 goose: successfully migrated database to version: 202609200000009642026/09/21 14:12:09 OK 1_commit_pending_closure.sql (2.53ms)9652026/09/21 14:12:09 OK 2_object_stats_trigger.sql (389.54µs)9662026/09/21 14:12:09 goose: up to current file version: 29672026-09-21 14:12:09.578 UTC [68337] ERROR: relation "goose_db_version" does not exist at character 369682026-09-21 14:12:09.578 UTC [68337] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9692026/09/21 14:12:09 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9702026/09/21 14:12:09 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst971--- PASS: TestCompleteMultipartUnregistered (2.38s)972=== CONT TestServerTLSConfig973=== RUN TestServerTLSConfig/no_client_CA974=== PAUSE TestServerTLSConfig/no_client_CA975=== RUN TestServerTLSConfig/missing_CA_file976=== PAUSE TestServerTLSConfig/missing_CA_file977=== RUN TestServerTLSConfig/not_a_PEM_file978=== PAUSE TestServerTLSConfig/not_a_PEM_file979=== CONT TestService_NativeMTLS9802026/09/21 14:12:09 OK 20241026095416_initial_model.sql (166.48ms)9812026/09/21 14:12:09 OK 20251210153512_drop_unused_gin_index.sql (25.82ms)9822026/09/21 14:12:09 OK 20251218171726_add_pins.sql (17.5ms)9832026/09/21 14:12:09 OK 20260628120000_add_object_size_and_stats.sql (31.74ms)9842026/09/21 14:12:09 OK 20260905000000_add_claims.sql (49.4ms)9852026/09/21 14:12:09 OK 20260920000000_drop_claims.sql (17.08ms)9862026/09/21 14:12:09 goose: successfully migrated database to version: 202609200000009872026/09/21 14:12:09 OK 1_commit_pending_closure.sql (4.49ms)9882026/09/21 14:12:09 OK 2_object_stats_trigger.sql (870.54µs)9892026/09/21 14:12:09 goose: up to current file version: 29902026/09/21 14:12:09 WARN readiness check failed error="closed pool"991--- PASS: TestService_readinessHandler (1.83s)992=== CONT TestMetricsInventory9932026/09/21 14:12:10 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9942026/09/21 14:12:10 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=MmI5ZWFhNjktZDkzNy00ZTdhLWI1ZWEtOGY1YzQ4YjQ5NjA2LjdhYmFkNzlhLTExNDgtNGRhZS1iNDRlLTAwNWZlZGE3YWM3ZHgxNzg5OTk5OTI4NTY3MTg3MDAw parts=129952026/09/21 14:12:10 INFO Received uploads request method=POST path=/api/pending_closures996--- PASS: TestCompletedNarNotReofferedAcrossClosures (2.78s)997=== CONT TestNARDeduplicationMetadataUploadBug9982026/09/21 14:12:10 INFO Received uploads request method=POST path=/api/pending_closures9992026-09-21 14:12:10.183 UTC [68345] ERROR: relation "goose_db_version" does not exist at character 3610002026-09-21 14:12:10.183 UTC [68345] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10012026-09-21 14:12:10.226 UTC [68346] ERROR: relation "goose_db_version" does not exist at character 3610022026-09-21 14:12:10.226 UTC [68346] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10032026-09-21 14:12:10.268 UTC [68347] ERROR: relation "goose_db_version" does not exist at character 3610042026-09-21 14:12:10.268 UTC [68347] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10052026/09/21 14:12:10 OK 20241026095416_initial_model.sql (63.93ms)10062026/09/21 14:12:10 OK 20251210153512_drop_unused_gin_index.sql (8.72ms)10072026/09/21 14:12:10 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10082026/09/21 14:12:10 OK 20251218171726_add_pins.sql (26.28ms)10092026/09/21 14:12:10 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=MmI5ZWFhNjktZDkzNy00ZTdhLWI1ZWEtOGY1YzQ4YjQ5NjA2LjU5OGUzMzFjLTRmNjYtNGZhYi04M2ExLTJmNTI1NjFhN2E5ZXgxNzg5OTk5OTMwMTg0OTI3MDAw10102026/09/21 14:12:10 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=MmI5ZWFhNjktZDkzNy00ZTdhLWI1ZWEtOGY1YzQ4YjQ5NjA2LjU5OGUzMzFjLTRmNjYtNGZhYi04M2ExLTJmNTI1NjFhN2E5ZXgxNzg5OTk5OTMwMTg0OTI3MDAw parts=11011--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (2.04s)1012=== CONT TestCreatePendingClosureRejectsOversizedNAR10132026/09/21 14:12:10 INFO Received uploads request method=POST path=/api/pending_closures1014--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)1015=== CONT TestReadProxyNarinfo10162026-09-21 14:12:10.324 UTC [68348] ERROR: relation "goose_db_version" does not exist at character 3610172026-09-21 14:12:10.324 UTC [68348] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10182026/09/21 14:12:10 OK 20241026095416_initial_model.sql (67.84ms)10192026/09/21 14:12:10 OK 20251210153512_drop_unused_gin_index.sql (1.26ms)10202026/09/21 14:12:10 OK 20260628120000_add_object_size_and_stats.sql (13.93ms)10212026/09/21 14:12:10 OK 20251218171726_add_pins.sql (3.34ms)10222026/09/21 14:12:10 OK 20260905000000_add_claims.sql (4.58ms)10232026/09/21 14:12:10 OK 20241026095416_initial_model.sql (19.08ms)10242026/09/21 14:12:10 OK 20260920000000_drop_claims.sql (2.08ms)10252026/09/21 14:12:10 goose: successfully migrated database to version: 2026092000000010262026/09/21 14:12:10 OK 20260628120000_add_object_size_and_stats.sql (3.94ms)10272026/09/21 14:12:10 OK 20251210153512_drop_unused_gin_index.sql (1.08ms)10282026/09/21 14:12:10 OK 1_commit_pending_closure.sql (1.67ms)10292026/09/21 14:12:10 OK 2_object_stats_trigger.sql (333.54µs)10302026/09/21 14:12:10 goose: up to current file version: 210312026/09/21 14:12:10 OK 20251218171726_add_pins.sql (3.62ms)10322026/09/21 14:12:10 OK 20260905000000_add_claims.sql (4.05ms)10332026/09/21 14:12:10 OK 20260920000000_drop_claims.sql (10.26ms)10342026/09/21 14:12:10 goose: successfully migrated database to version: 2026092000000010352026/09/21 14:12:10 OK 1_commit_pending_closure.sql (1.66ms)10362026/09/21 14:12:10 OK 2_object_stats_trigger.sql (350.04µs)10372026/09/21 14:12:10 goose: up to current file version: 210382026/09/21 14:12:10 OK 20260628120000_add_object_size_and_stats.sql (18.94ms)10392026/09/21 14:12:10 OK 20260905000000_add_claims.sql (13.47ms)10402026/09/21 14:12:10 OK 20241026095416_initial_model.sql (40.38ms)10412026/09/21 14:12:10 OK 20251210153512_drop_unused_gin_index.sql (1.06ms)10422026/09/21 14:12:10 OK 20260920000000_drop_claims.sql (8.43ms)10432026/09/21 14:12:10 goose: successfully migrated database to version: 2026092000000010442026/09/21 14:12:10 OK 1_commit_pending_closure.sql (1.39ms)10452026/09/21 14:12:10 OK 2_object_stats_trigger.sql (305.25µs)10462026/09/21 14:12:10 goose: up to current file version: 210472026/09/21 14:12:10 OK 20251218171726_add_pins.sql (16.16ms)10482026/09/21 14:12:10 OK 20260628120000_add_object_size_and_stats.sql (12.64ms)10492026/09/21 14:12:10 OK 20260905000000_add_claims.sql (15.73ms)10502026/09/21 14:12:10 OK 20260920000000_drop_claims.sql (13.58ms)10512026/09/21 14:12:10 goose: successfully migrated database to version: 2026092000000010522026/09/21 14:12:10 OK 1_commit_pending_closure.sql (1.83ms)10532026/09/21 14:12:10 OK 2_object_stats_trigger.sql (357.25µs)10542026/09/21 14:12:10 goose: up to current file version: 21055--- PASS: TestResurrectedObjectNotDeleted (1.73s)1056=== CONT TestCacheConfigHandlerMaxNarSize1057--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)1058=== CONT TestRedundantMultipartUpload10592026-09-21 14:12:10.694 UTC [68353] ERROR: relation "goose_db_version" does not exist at character 3610602026-09-21 14:12:10.694 UTC [68353] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10612026-09-21 14:12:10.745 UTC [68354] ERROR: relation "goose_db_version" does not exist at character 3610622026-09-21 14:12:10.745 UTC [68354] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10632026/09/21 14:12:10 OK 20241026095416_initial_model.sql (98.78ms)10642026/09/21 14:12:10 OK 20251210153512_drop_unused_gin_index.sql (3.77ms)10652026/09/21 14:12:10 OK 20251218171726_add_pins.sql (5.41ms)10662026/09/21 14:12:10 OK 20241026095416_initial_model.sql (73.13ms)10672026/09/21 14:12:10 OK 20260628120000_add_object_size_and_stats.sql (27.95ms)10682026/09/21 14:12:10 OK 20251210153512_drop_unused_gin_index.sql (7.2ms)10692026/09/21 14:12:10 OK 20251218171726_add_pins.sql (10.63ms)10702026/09/21 14:12:10 OK 20260905000000_add_claims.sql (16.24ms)10712026/09/21 14:12:10 OK 20260920000000_drop_claims.sql (5.87ms)10722026/09/21 14:12:10 goose: successfully migrated database to version: 2026092000000010732026-09-21 14:12:10.901 UTC [68355] ERROR: relation "goose_db_version" does not exist at character 3610742026-09-21 14:12:10.901 UTC [68355] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10752026/09/21 14:12:10 OK 1_commit_pending_closure.sql (37.89ms)10762026/09/21 14:12:10 OK 20260628120000_add_object_size_and_stats.sql (47.96ms)10772026/09/21 14:12:10 OK 2_object_stats_trigger.sql (1.59ms)10782026/09/21 14:12:10 goose: up to current file version: 210792026/09/21 14:12:10 OK 20260905000000_add_claims.sql (12.83ms)10802026-09-21 14:12:10.945 UTC [68356] ERROR: relation "goose_db_version" does not exist at character 3610812026-09-21 14:12:10.945 UTC [68356] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10822026/09/21 14:12:10 OK 20260920000000_drop_claims.sql (9.23ms)10832026/09/21 14:12:10 goose: successfully migrated database to version: 2026092000000010842026/09/21 14:12:10 OK 1_commit_pending_closure.sql (2.17ms)10852026/09/21 14:12:10 OK 2_object_stats_trigger.sql (658.29µs)10862026/09/21 14:12:10 goose: up to current file version: 210872026/09/21 14:12:11 OK 20241026095416_initial_model.sql (85.96ms)10882026/09/21 14:12:11 OK 20251210153512_drop_unused_gin_index.sql (2.48ms)10892026/09/21 14:12:11 OK 20251218171726_add_pins.sql (4.19ms)10902026/09/21 14:12:11 OK 20241026095416_initial_model.sql (70.74ms)1091--- PASS: TestObjectStatsTrigger (1.91s)1092=== CONT TestGenerateLandingPage1093--- PASS: TestGenerateLandingPage (0.00s)1094=== CONT TestReadRedirectUsesPublicS3URL10952026/09/21 14:12:11 OK 20260628120000_add_object_size_and_stats.sql (26.73ms)10962026/09/21 14:12:11 OK 20251210153512_drop_unused_gin_index.sql (15.33ms)10972026/09/21 14:12:11 OK 20251218171726_add_pins.sql (4.12ms)10982026/09/21 14:12:11 OK 20260905000000_add_claims.sql (11.93ms)10992026/09/21 14:12:11 OK 20260628120000_add_object_size_and_stats.sql (7.85ms)11002026/09/21 14:12:11 OK 20260920000000_drop_claims.sql (13.89ms)11012026/09/21 14:12:11 goose: successfully migrated database to version: 2026092000000011022026/09/21 14:12:11 OK 1_commit_pending_closure.sql (1.77ms)11032026/09/21 14:12:11 OK 2_object_stats_trigger.sql (320.38µs)11042026/09/21 14:12:11 goose: up to current file version: 211052026/09/21 14:12:11 OK 20260905000000_add_claims.sql (18.1ms)11062026/09/21 14:12:11 OK 20260920000000_drop_claims.sql (6.72ms)11072026/09/21 14:12:11 goose: successfully migrated database to version: 2026092000000011082026/09/21 14:12:11 OK 1_commit_pending_closure.sql (1.48ms)11092026/09/21 14:12:11 OK 2_object_stats_trigger.sql (335.08µs)11102026/09/21 14:12:11 goose: up to current file version: 21111=== NAME TestOrphanedObjectsGC1112 orphaned_objects_gc_test.go:290: GC Test Summary:1113 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A1114 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B1115 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)1116 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)1117 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects1118--- PASS: TestOrphanedObjectsGC (2.06s)1119=== CONT TestReadProxyConditionalGet11202026-09-21 14:12:11.160 UTC [68359] ERROR: relation "goose_db_version" does not exist at character 3611212026-09-21 14:12:11.160 UTC [68359] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11222026/09/21 14:12:11 INFO Received uploads request method=POST path=/api/pending_closures11232026/09/21 14:12:11 OK 20241026095416_initial_model.sql (42.02ms)11242026/09/21 14:12:11 OK 20251210153512_drop_unused_gin_index.sql (8.92ms)11252026/09/21 14:12:11 OK 20251218171726_add_pins.sql (12.26ms)11262026/09/21 14:12:11 OK 20260628120000_add_object_size_and_stats.sql (13.6ms)11272026/09/21 14:12:11 OK 20260905000000_add_claims.sql (16.8ms)11282026/09/21 14:12:11 OK 20260920000000_drop_claims.sql (29.89ms)11292026/09/21 14:12:11 goose: successfully migrated database to version: 2026092000000011302026/09/21 14:12:11 OK 1_commit_pending_closure.sql (4.45ms)11312026/09/21 14:12:11 OK 2_object_stats_trigger.sql (824.63µs)11322026/09/21 14:12:11 goose: up to current file version: 211332026/09/21 14:12:11 INFO Received cleanup request method=DELETE path=/api/pending_closures11342026/09/21 14:12:11 INFO Aborted multipart uploads count=11135--- PASS: TestMultipartCleanup (1.85s)1136=== CONT TestReadProxyHead11372026/09/21 14:12:11 WARN mTLS auth: subject not in bound subjects subject="CN=reader"11382026/09/21 14:12:11 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1139--- PASS: TestService_NativeMTLS (1.65s)1140=== CONT TestReadProxyRangeRequest11412026-09-21 14:12:11.388 UTC [68365] ERROR: relation "goose_db_version" does not exist at character 3611422026-09-21 14:12:11.388 UTC [68365] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11432026/09/21 14:12:11 OK 20241026095416_initial_model.sql (77.87ms)11442026/09/21 14:12:11 OK 20251210153512_drop_unused_gin_index.sql (1.63ms)11452026/09/21 14:12:11 OK 20251218171726_add_pins.sql (28.17ms)11462026/09/21 14:12:11 OK 20260628120000_add_object_size_and_stats.sql (11.08ms)1147--- PASS: TestMetricsInventory (1.59s)1148=== CONT TestReadProxyInvalidPath11492026/09/21 14:12:11 OK 20260905000000_add_claims.sql (21.72ms)11502026/09/21 14:12:11 OK 20260920000000_drop_claims.sql (18.68ms)11512026/09/21 14:12:11 goose: successfully migrated database to version: 2026092000000011522026/09/21 14:12:11 OK 1_commit_pending_closure.sql (1.78ms)11532026/09/21 14:12:11 OK 2_object_stats_trigger.sql (374.42µs)11542026/09/21 14:12:11 goose: up to current file version: 21155=== NAME TestNARDeduplicationMetadataUploadBug1156 metadata_upload_test.go:48: First store path: /nix/var/nix/builds/nix-68162-1667843226/TestNARDeduplicationMetadataUploadBug2253892976/001/store/ycbls3sgdl7rsajn2pmh8smfsdxl62b9-file1.txt11572026-09-21 14:12:11.845 UTC [68371] ERROR: relation "goose_db_version" does not exist at character 3611582026-09-21 14:12:11.845 UTC [68371] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1159--- PASS: TestReadProxyNarinfo (1.53s)1160=== CONT TestReadRedirectKeepsNarinfoProxied11612026/09/21 14:12:11 OK 20241026095416_initial_model.sql (51.1ms)11622026/09/21 14:12:11 OK 20251210153512_drop_unused_gin_index.sql (6.43ms)11632026/09/21 14:12:11 OK 20251218171726_add_pins.sql (8.08ms)11642026-09-21 14:12:11.947 UTC [68378] ERROR: relation "goose_db_version" does not exist at character 3611652026-09-21 14:12:11.947 UTC [68378] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11662026/09/21 14:12:11 OK 20260628120000_add_object_size_and_stats.sql (17.47ms)11672026/09/21 14:12:11 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"11682026/09/21 14:12:11 OK 20260905000000_add_claims.sql (36.44ms)11692026/09/21 14:12:12 OK 20260920000000_drop_claims.sql (17.64ms)11702026/09/21 14:12:12 goose: successfully migrated database to version: 2026092000000011712026/09/21 14:12:12 OK 1_commit_pending_closure.sql (929.88µs)11722026/09/21 14:12:12 OK 2_object_stats_trigger.sql (250.54µs)11732026/09/21 14:12:12 goose: up to current file version: 211742026/09/21 14:12:12 INFO Received uploads request method=POST path=/api/pending_closures11752026/09/21 14:12:12 INFO Received uploads request method=POST path=/api/pending_closures11762026/09/21 14:12:12 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)11772026/09/21 14:12:12 INFO Uploading ycbls3sgdl7rsajn2pmh8smfsdxl62b9-file1.txt (160B)11782026/09/21 14:12:12 INFO Received uploads request method=POST path=/api/pending_closures11792026/09/21 14:12:12 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"11802026/09/21 14:12:12 OK 20241026095416_initial_model.sql (76.53ms)11812026/09/21 14:12:12 OK 20251210153512_drop_unused_gin_index.sql (790.88µs)11822026/09/21 14:12:12 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign11832026/09/21 14:12:12 INFO Signed narinfos id=1 count=111842026/09/21 14:12:12 WARN Failed to register uploaded object key=ycbls3sgdl7rsajn2pmh8smfsdxl62b9.ls error="server returned 404: 404 page not found\n"11852026/09/21 14:12:12 INFO Uploading 1 narinfos11862026/09/21 14:12:12 OK 20251218171726_add_pins.sql (28.45ms)11872026/09/21 14:12:12 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete11882026/09/21 14:12:12 WARN Failed to register uploaded object key=ycbls3sgdl7rsajn2pmh8smfsdxl62b9.narinfo error="server returned 404: 404 page not found\n"11892026/09/21 14:12:12 INFO Completed upload id=111902026/09/21 14:12:12 INFO Upload complete. (221ms)1191=== NAME TestNARDeduplicationMetadataUploadBug1192 metadata_upload_test.go:54: Retrieved narinfo from S3:1193 StorePath: /nix/var/nix/builds/nix-68162-1667843226/TestNARDeduplicationMetadataUploadBug2253892976/001/store/ycbls3sgdl7rsajn2pmh8smfsdxl62b9-file1.txt1194 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1195 Compression: zstd1196 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1197 NarSize: 1601198 References: 1199 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1200 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1201 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1202 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}12032026/09/21 14:12:12 OK 20260628120000_add_object_size_and_stats.sql (16.27ms)12042026/09/21 14:12:12 OK 20260905000000_add_claims.sql (59.37ms)12052026/09/21 14:12:12 OK 20260920000000_drop_claims.sql (25.48ms)12062026/09/21 14:12:12 goose: successfully migrated database to version: 2026092000000012072026/09/21 14:12:12 OK 1_commit_pending_closure.sql (988.67µs)12082026/09/21 14:12:12 OK 2_object_stats_trigger.sql (241.46µs)12092026/09/21 14:12:12 goose: up to current file version: 21210 metadata_upload_test.go:64: Second store path (same content): /nix/var/nix/builds/nix-68162-1667843226/TestNARDeduplicationMetadataUploadBug2253892976/001/store/8qqr8lzrqnk4b3kjfs3bin8qfzhl7x4i-file2.txt1211--- PASS: TestReadRedirectUsesPublicS3URL (1.22s)1212=== CONT TestReadProxy40412132026/09/21 14:12:12 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"12142026-09-21 14:12:12.308 UTC [68388] ERROR: relation "goose_db_version" does not exist at character 3612152026-09-21 14:12:12.308 UTC [68388] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12162026/09/21 14:12:12 INFO Received uploads request method=POST path=/api/pending_closures12172026/09/21 14:12:12 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)12182026/09/21 14:12:12 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign12192026/09/21 14:12:12 INFO Signed narinfos id=2 count=112202026/09/21 14:12:12 INFO Uploading 1 narinfos12212026/09/21 14:12:12 WARN Failed to register uploaded object key=8qqr8lzrqnk4b3kjfs3bin8qfzhl7x4i.ls error="server returned 404: 404 page not found\n"12222026/09/21 14:12:12 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete12232026/09/21 14:12:12 WARN Failed to register uploaded object key=8qqr8lzrqnk4b3kjfs3bin8qfzhl7x4i.narinfo error="server returned 404: 404 page not found\n"12242026/09/21 14:12:12 INFO Completed upload id=212252026/09/21 14:12:12 INFO Upload complete. (148ms)1226=== NAME TestNARDeduplicationMetadataUploadBug1227 metadata_upload_test.go:76: Retrieved narinfo from S3:1228 StorePath: /nix/var/nix/builds/nix-68162-1667843226/TestNARDeduplicationMetadataUploadBug2253892976/001/store/8qqr8lzrqnk4b3kjfs3bin8qfzhl7x4i-file2.txt1229 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1230 Compression: zstd1231 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1232 NarSize: 1601233 References: 1234 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1235 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1236 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1237 {"version":1,"root":{"type":"regular","size":44}}12382026-09-21 14:12:12.393 UTC [68392] ERROR: relation "goose_db_version" does not exist at character 3612392026-09-21 14:12:12.393 UTC [68392] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1240--- PASS: TestNARDeduplicationMetadataUploadBug (2.34s)1241=== CONT TestReadRedirectNar12422026/09/21 14:12:12 OK 20241026095416_initial_model.sql (117.93ms)12432026/09/21 14:12:12 OK 20251210153512_drop_unused_gin_index.sql (725.54µs)12442026/09/21 14:12:12 OK 20251218171726_add_pins.sql (1.06ms)1245--- PASS: TestReadProxyConditionalGet (1.36s)1246=== CONT TestReadProxyNarStreaming12472026-09-21 14:12:12.504 UTC [68395] ERROR: relation "goose_db_version" does not exist at character 3612482026-09-21 14:12:12.504 UTC [68395] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12492026/09/21 14:12:12 OK 20260628120000_add_object_size_and_stats.sql (7.16ms)12502026/09/21 14:12:12 OK 20241026095416_initial_model.sql (59.56ms)12512026/09/21 14:12:12 OK 20251210153512_drop_unused_gin_index.sql (753.46µs)12522026/09/21 14:12:12 OK 20251218171726_add_pins.sql (16.25ms)12532026/09/21 14:12:12 OK 20260905000000_add_claims.sql (46.81ms)12542026/09/21 14:12:12 OK 20260628120000_add_object_size_and_stats.sql (29.73ms)12552026/09/21 14:12:12 OK 20260920000000_drop_claims.sql (8.06ms)12562026/09/21 14:12:12 goose: successfully migrated database to version: 2026092000000012572026/09/21 14:12:12 OK 20260905000000_add_claims.sql (8.9ms)12582026/09/21 14:12:12 OK 1_commit_pending_closure.sql (1.84ms)12592026/09/21 14:12:12 OK 20260920000000_drop_claims.sql (1.15ms)12602026/09/21 14:12:12 goose: successfully migrated database to version: 2026092000000012612026/09/21 14:12:12 OK 2_object_stats_trigger.sql (375.38µs)12622026/09/21 14:12:12 goose: up to current file version: 212632026/09/21 14:12:12 OK 1_commit_pending_closure.sql (1.79ms)12642026/09/21 14:12:12 OK 20241026095416_initial_model.sql (35.35ms)12652026/09/21 14:12:12 OK 2_object_stats_trigger.sql (642.88µs)12662026/09/21 14:12:12 goose: up to current file version: 212672026/09/21 14:12:12 OK 20251210153512_drop_unused_gin_index.sql (458.96µs)12682026/09/21 14:12:12 OK 20251218171726_add_pins.sql (16.46ms)12692026/09/21 14:12:12 OK 20260628120000_add_object_size_and_stats.sql (33.74ms)12702026/09/21 14:12:12 OK 20260905000000_add_claims.sql (33.58ms)12712026/09/21 14:12:12 OK 20260920000000_drop_claims.sql (13.9ms)12722026/09/21 14:12:12 goose: successfully migrated database to version: 2026092000000012732026/09/21 14:12:12 OK 1_commit_pending_closure.sql (1.34ms)12742026/09/21 14:12:12 OK 2_object_stats_trigger.sql (259.83µs)12752026/09/21 14:12:12 goose: up to current file version: 21276--- PASS: TestReadProxyHead (1.46s)1277=== CONT TestReadProxyNarinfoAlreadyDecompressed12782026-09-21 14:12:12.995 UTC [68400] ERROR: relation "goose_db_version" does not exist at character 3612792026-09-21 14:12:12.995 UTC [68400] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1280--- PASS: TestReadProxyRangeRequest (1.65s)1281=== CONT TestReadProxyDisabled12822026/09/21 14:12:13 OK 20241026095416_initial_model.sql (131.87ms)12832026/09/21 14:12:13 OK 20251210153512_drop_unused_gin_index.sql (7.69ms)1284--- PASS: TestReadProxyInvalidPath (1.64s)1285=== CONT TestReadProxyRootRedirectsToIndexHTML12862026/09/21 14:12:13 OK 20251218171726_add_pins.sql (30.78ms)12872026/09/21 14:12:13 OK 20260628120000_add_object_size_and_stats.sql (37ms)12882026/09/21 14:12:13 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12892026/09/21 14:12:13 OK 20260905000000_add_claims.sql (82.55ms)12902026/09/21 14:12:13 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=MmI5ZWFhNjktZDkzNy00ZTdhLWI1ZWEtOGY1YzQ4YjQ5NjA2LmFjNDg2MzlkLTQ2OTctNDgwOC1iMzBjLTMzNjI5MmEzYzk1NXgxNzg5OTk5OTMyMDI4MDQwMDAw parts=121291--- PASS: TestRedundantMultipartUpload (2.78s)1292=== CONT TestResolveDBConnectionString1293=== RUN TestResolveDBConnectionString/flag_wins1294=== PAUSE TestResolveDBConnectionString/flag_wins1295=== RUN TestResolveDBConnectionString/file_when_flag_empty1296=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1297=== RUN TestResolveDBConnectionString/missing_file_is_an_error1298=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1299=== RUN TestResolveDBConnectionString/PGHOST_allows_empty1300=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1301=== RUN TestResolveDBConnectionString/nothing_configured1302=== PAUSE TestResolveDBConnectionString/nothing_configured1303=== CONT TestService_healthCheckHandler13042026/09/21 14:12:13 OK 20260920000000_drop_claims.sql (37.52ms)13052026/09/21 14:12:13 goose: successfully migrated database to version: 2026092000000013062026/09/21 14:12:13 OK 1_commit_pending_closure.sql (3.72ms)13072026/09/21 14:12:13 OK 2_object_stats_trigger.sql (740.38µs)13082026/09/21 14:12:13 goose: up to current file version: 213092026-09-21 14:12:13.576 UTC [68407] ERROR: relation "goose_db_version" does not exist at character 3613102026-09-21 14:12:13.576 UTC [68407] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1311--- PASS: TestReadRedirectKeepsNarinfoProxied (1.85s)1312=== CONT TestGracefulShutdownDrainsInflight13132026/09/21 14:12:13 INFO Starting HTTP server address=127.0.0.1:6190813142026/09/21 14:12:13 INFO Shutdown signal received, draining in-flight requests timeout=10s13152026/09/21 14:12:13 OK 20241026095416_initial_model.sql (79.3ms)13162026/09/21 14:12:13 OK 20251210153512_drop_unused_gin_index.sql (2.43ms)13172026/09/21 14:12:13 OK 20251218171726_add_pins.sql (4.49ms)13182026-09-21 14:12:13.724 UTC [68408] ERROR: relation "goose_db_version" does not exist at character 3613192026-09-21 14:12:13.724 UTC [68408] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13202026/09/21 14:12:13 OK 20260628120000_add_object_size_and_stats.sql (10.25ms)13212026-09-21 14:12:13.729 UTC [68409] ERROR: relation "goose_db_version" does not exist at character 3613222026-09-21 14:12:13.729 UTC [68409] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13232026/09/21 14:12:13 OK 20260905000000_add_claims.sql (3.6ms)13242026/09/21 14:12:13 OK 20260920000000_drop_claims.sql (2.03ms)13252026/09/21 14:12:13 goose: successfully migrated database to version: 2026092000000013262026/09/21 14:12:13 OK 1_commit_pending_closure.sql (2.15ms)13272026/09/21 14:12:13 OK 2_object_stats_trigger.sql (686.54µs)13282026/09/21 14:12:13 goose: up to current file version: 21329--- PASS: TestGracefulShutdownDrainsInflight (0.07s)1330=== CONT TestGCTaskStore_Fail1331--- PASS: TestGCTaskStore_Fail (0.00s)1332=== CONT TestGCTaskStore_PhaseUpdates1333--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)1334=== CONT TestGCTaskStore_CompletedAllowsNewTask1335--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)1336=== CONT TestGCTaskStore_GetReturnsLatest1337--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)1338=== CONT TestGCTaskStore_GetEmpty1339--- PASS: TestGCTaskStore_GetEmpty (0.00s)1340=== CONT TestGCTaskStore_ConflictDifferentParams1341--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)1342=== CONT TestGCTaskStore_DeduplicateSameParams1343--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)1344=== CONT TestGCTaskStore_StartNew1345--- PASS: TestGCTaskStore_StartNew (0.00s)1346=== CONT TestGCMetrics13472026/09/21 14:12:13 OK 20241026095416_initial_model.sql (89.07ms)13482026/09/21 14:12:13 OK 20251210153512_drop_unused_gin_index.sql (1.06ms)13492026/09/21 14:12:13 OK 20251218171726_add_pins.sql (7.67ms)13502026/09/21 14:12:13 OK 20241026095416_initial_model.sql (107.71ms)13512026/09/21 14:12:13 OK 20260628120000_add_object_size_and_stats.sql (14.68ms)13522026/09/21 14:12:13 OK 20251210153512_drop_unused_gin_index.sql (1.52ms)13532026/09/21 14:12:13 OK 20251218171726_add_pins.sql (7.82ms)13542026/09/21 14:12:13 OK 20260905000000_add_claims.sql (16.46ms)13552026/09/21 14:12:13 OK 20260920000000_drop_claims.sql (9.91ms)13562026/09/21 14:12:13 goose: successfully migrated database to version: 2026092000000013572026/09/21 14:12:13 OK 1_commit_pending_closure.sql (1.8ms)13582026/09/21 14:12:13 OK 2_object_stats_trigger.sql (381.38µs)13592026/09/21 14:12:13 goose: up to current file version: 213602026/09/21 14:12:13 OK 20260628120000_add_object_size_and_stats.sql (25.98ms)13612026/09/21 14:12:13 OK 20260905000000_add_claims.sql (62.13ms)1362--- PASS: TestReadProxy404 (1.69s)1363=== CONT TestGCBugBareHashReferences13642026/09/21 14:12:13 OK 20260920000000_drop_claims.sql (47.14ms)13652026/09/21 14:12:13 goose: successfully migrated database to version: 2026092000000013662026/09/21 14:12:13 OK 1_commit_pending_closure.sql (1.61ms)13672026/09/21 14:12:13 OK 2_object_stats_trigger.sql (378.17µs)13682026/09/21 14:12:13 goose: up to current file version: 21369--- PASS: TestReadRedirectNar (1.81s)1370=== CONT TestLeadEndsOnShutdown13712026-09-21 14:12:14.274 UTC [68415] ERROR: relation "goose_db_version" does not exist at character 3613722026-09-21 14:12:14.274 UTC [68415] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13732026/09/21 14:12:14 WARN Rate limiter enabled after throttle name=s3-test rate=513742026/09/21 14:12:14 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."1375=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle1376 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=101377 throttle_test.go:215: Rate limiter: enabled=true, rate=5.001378--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (7.03s)1379=== CONT TestLeadElectsOneAndHandsOver13802026-09-21 14:12:14.435 UTC [68418] ERROR: relation "goose_db_version" does not exist at character 3613812026-09-21 14:12:14.435 UTC [68418] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13822026/09/21 14:12:14 OK 20241026095416_initial_model.sql (131.49ms)1383--- PASS: TestReadProxyNarStreaming (1.93s)1384=== CONT TestCacheStatsHandler13852026/09/21 14:12:14 OK 20251210153512_drop_unused_gin_index.sql (16.39ms)1386=== NAME TestOrphanedObjectsGCStressTest1387 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains13882026/09/21 14:12:14 OK 20251218171726_add_pins.sql (13.27ms)13892026/09/21 14:12:14 OK 20260628120000_add_object_size_and_stats.sql (19.03ms)13902026/09/21 14:12:14 OK 20260905000000_add_claims.sql (34.18ms)1391 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion13922026/09/21 14:12:14 OK 20260920000000_drop_claims.sql (26.28ms)13932026/09/21 14:12:14 goose: successfully migrated database to version: 2026092000000013942026/09/21 14:12:14 OK 1_commit_pending_closure.sql (2.67ms)13952026/09/21 14:12:14 OK 2_object_stats_trigger.sql (677.33µs)13962026/09/21 14:12:14 goose: up to current file version: 213972026/09/21 14:12:14 OK 20241026095416_initial_model.sql (81.13ms)13982026/09/21 14:12:14 OK 20251210153512_drop_unused_gin_index.sql (739.67µs)13992026-09-21 14:12:14.553 UTC [68422] ERROR: relation "goose_db_version" does not exist at character 3614002026-09-21 14:12:14.553 UTC [68422] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14012026/09/21 14:12:14 OK 20251218171726_add_pins.sql (4.44ms)14022026/09/21 14:12:14 OK 20260628120000_add_object_size_and_stats.sql (39.37ms)14032026/09/21 14:12:14 OK 20260905000000_add_claims.sql (58.5ms)14042026/09/21 14:12:14 OK 20260920000000_drop_claims.sql (20.49ms)14052026/09/21 14:12:14 goose: successfully migrated database to version: 2026092000000014062026/09/21 14:12:14 OK 1_commit_pending_closure.sql (2ms)14072026/09/21 14:12:14 OK 2_object_stats_trigger.sql (404.33µs)14082026/09/21 14:12:14 goose: up to current file version: 214092026/09/21 14:12:14 OK 20241026095416_initial_model.sql (143.79ms)14102026/09/21 14:12:14 OK 20251210153512_drop_unused_gin_index.sql (8.56ms)14112026/09/21 14:12:14 OK 20251218171726_add_pins.sql (53.17ms)1412--- PASS: TestReadProxyNarinfoAlreadyDecompressed (2.04s)1413=== CONT TestPinProtectsFromGC14142026/09/21 14:12:14 OK 20260628120000_add_object_size_and_stats.sql (54.07ms)14152026/09/21 14:12:14 OK 20260905000000_add_claims.sql (44.02ms)14162026/09/21 14:12:14 OK 20260920000000_drop_claims.sql (38.32ms)14172026/09/21 14:12:14 goose: successfully migrated database to version: 2026092000000014182026/09/21 14:12:14 OK 1_commit_pending_closure.sql (2.67ms)14192026/09/21 14:12:14 OK 2_object_stats_trigger.sql (530µs)14202026/09/21 14:12:14 goose: up to current file version: 21421--- PASS: TestReadProxyDisabled (2.07s)1422=== CONT TestClientSharedPathCommittedMidPush14232026-09-21 14:12:15.111 UTC [68425] ERROR: relation "goose_db_version" does not exist at character 3614242026-09-21 14:12:15.111 UTC [68425] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14252026/09/21 14:12:15 OK 20241026095416_initial_model.sql (98.29ms)14262026/09/21 14:12:15 OK 20251210153512_drop_unused_gin_index.sql (9.32ms)14272026-09-21 14:12:15.277 UTC [68428] ERROR: relation "goose_db_version" does not exist at character 3614282026-09-21 14:12:15.277 UTC [68428] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14292026/09/21 14:12:15 OK 20251218171726_add_pins.sql (25.2ms)1430--- PASS: TestReadProxyRootRedirectsToIndexHTML (2.09s)1431=== CONT TestService_AuthMiddleware_OIDC14322026/09/21 14:12:15 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:61931/oidc14332026/09/21 14:12:15 OK 20260628120000_add_object_size_and_stats.sql (9.9ms)14342026/09/21 14:12:15 OK 20260905000000_add_claims.sql (5.43ms)14352026/09/21 14:12:15 OK 20260920000000_drop_claims.sql (1.86ms)14362026/09/21 14:12:15 goose: successfully migrated database to version: 2026092000000014372026/09/21 14:12:15 OK 1_commit_pending_closure.sql (3.11ms)14382026/09/21 14:12:15 OK 2_object_stats_trigger.sql (639.21µs)14392026/09/21 14:12:15 goose: up to current file version: 214402026-09-21 14:12:15.315 UTC [68430] ERROR: relation "goose_db_version" does not exist at character 3614412026-09-21 14:12:15.315 UTC [68430] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14422026/09/21 14:12:15 OK 20241026095416_initial_model.sql (34.09ms)14432026/09/21 14:12:15 OK 20251210153512_drop_unused_gin_index.sql (1.79ms)14442026/09/21 14:12:15 OK 20251218171726_add_pins.sql (16.6ms)14452026/09/21 14:12:15 OK 20260628120000_add_object_size_and_stats.sql (9.95ms)14462026/09/21 14:12:15 OK 20260905000000_add_claims.sql (23.09ms)14472026/09/21 14:12:15 OK 20260920000000_drop_claims.sql (14.46ms)14482026/09/21 14:12:15 goose: successfully migrated database to version: 2026092000000014492026/09/21 14:12:15 OK 1_commit_pending_closure.sql (2.27ms)14502026/09/21 14:12:15 OK 2_object_stats_trigger.sql (358.88µs)14512026/09/21 14:12:15 goose: up to current file version: 214522026/09/21 14:12:15 OK 20241026095416_initial_model.sql (90.03ms)14532026/09/21 14:12:15 OK 20251210153512_drop_unused_gin_index.sql (7.48ms)1454--- PASS: TestService_healthCheckHandler (2.13s)1455=== CONT TestClientWithDependencies14562026/09/21 14:12:15 OK 20251218171726_add_pins.sql (33.48ms)14572026/09/21 14:12:15 OK 20260628120000_add_object_size_and_stats.sql (13.1ms)14582026/09/21 14:12:15 OK 20260905000000_add_claims.sql (17.64ms)14592026/09/21 14:12:15 OK 20260920000000_drop_claims.sql (13.28ms)14602026/09/21 14:12:15 goose: successfully migrated database to version: 2026092000000014612026/09/21 14:12:15 OK 1_commit_pending_closure.sql (1.93ms)14622026/09/21 14:12:15 OK 2_object_stats_trigger.sql (401.83µs)14632026/09/21 14:12:15 goose: up to current file version: 214642026-09-21 14:12:15.547 UTC [68434] ERROR: relation "goose_db_version" does not exist at character 3614652026-09-21 14:12:15.547 UTC [68434] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14662026-09-21 14:12:15.625 UTC [68435] ERROR: relation "goose_db_version" does not exist at character 3614672026-09-21 14:12:15.625 UTC [68435] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14682026/09/21 14:12:15 OK 20241026095416_initial_model.sql (86.77ms)14692026/09/21 14:12:15 OK 20251210153512_drop_unused_gin_index.sql (8.89ms)14702026/09/21 14:12:15 OK 20251218171726_add_pins.sql (22.74ms)14712026/09/21 14:12:15 INFO Aborted multipart uploads count=014722026/09/21 14:12:15 OK 20260628120000_add_object_size_and_stats.sql (12.41ms)14732026/09/21 14:12:15 WARN Force mode enabled - objects will be deleted immediately without grace period14742026/09/21 14:12:15 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=014752026/09/21 14:12:15 INFO Vacuumed table table=pending_closures14762026/09/21 14:12:15 INFO Vacuumed table table=pending_objects14772026/09/21 14:12:15 INFO Vacuumed table table=multipart_uploads14782026/09/21 14:12:15 INFO Vacuumed table table=closures14792026/09/21 14:12:15 INFO Vacuumed table table=objects1480--- PASS: TestGCMetrics (1.97s)1481=== CONT TestClientMultipleUploads14822026/09/21 14:12:15 OK 20260905000000_add_claims.sql (40.38ms)14832026/09/21 14:12:15 OK 20241026095416_initial_model.sql (93.11ms)14842026/09/21 14:12:15 OK 20251210153512_drop_unused_gin_index.sql (19.69ms)14852026/09/21 14:12:15 OK 20260920000000_drop_claims.sql (21.78ms)14862026/09/21 14:12:15 goose: successfully migrated database to version: 2026092000000014872026/09/21 14:12:15 OK 1_commit_pending_closure.sql (1.69ms)14882026/09/21 14:12:15 OK 2_object_stats_trigger.sql (343.58µs)14892026/09/21 14:12:15 goose: up to current file version: 214902026-09-21 14:12:15.790 UTC [68438] ERROR: relation "goose_db_version" does not exist at character 3614912026-09-21 14:12:15.790 UTC [68438] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14922026/09/21 14:12:15 OK 20251218171726_add_pins.sql (17.64ms)14932026/09/21 14:12:15 OK 20260628120000_add_object_size_and_stats.sql (21.33ms)14942026/09/21 14:12:15 OK 20260905000000_add_claims.sql (26.78ms)14952026/09/21 14:12:15 OK 20260920000000_drop_claims.sql (28.88ms)14962026/09/21 14:12:15 goose: successfully migrated database to version: 2026092000000014972026/09/21 14:12:15 OK 1_commit_pending_closure.sql (2.3ms)14982026/09/21 14:12:15 OK 2_object_stats_trigger.sql (407.13µs)14992026/09/21 14:12:15 goose: up to current file version: 215002026/09/21 14:12:15 OK 20241026095416_initial_model.sql (79.91ms)15012026/09/21 14:12:15 OK 20251210153512_drop_unused_gin_index.sql (9.77ms)15022026/09/21 14:12:15 OK 20251218171726_add_pins.sql (8.63ms)15032026/09/21 14:12:15 OK 20260628120000_add_object_size_and_stats.sql (20.09ms)15042026/09/21 14:12:15 OK 20260905000000_add_claims.sql (32.09ms)15052026/09/21 14:12:15 OK 20260920000000_drop_claims.sql (6.43ms)15062026/09/21 14:12:15 goose: successfully migrated database to version: 2026092000000015072026/09/21 14:12:15 OK 1_commit_pending_closure.sql (2.81ms)15082026/09/21 14:12:15 OK 2_object_stats_trigger.sql (662.88µs)15092026/09/21 14:12:15 goose: up to current file version: 215102026-09-21 14:12:16.057 UTC [68440] ERROR: relation "goose_db_version" does not exist at character 3615112026-09-21 14:12:16.057 UTC [68440] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15122026/09/21 14:12:16 INFO lead: acquired remote=192.0.2.1:123415132026/09/21 14:12:16 INFO lead: released remote=192.0.2.1:12341514--- PASS: TestLeadEndsOnShutdown (1.87s)1515=== CONT TestClientIntegration15162026-09-21 14:12:16.136 UTC [68443] ERROR: relation "goose_db_version" does not exist at character 3615172026-09-21 14:12:16.136 UTC [68443] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1518--- PASS: TestGCBugBareHashReferences (2.19s)1519=== CONT TestClientErrorHandling1520=== RUN TestClientErrorHandling/InvalidStorePath1521=== PAUSE TestClientErrorHandling/InvalidStorePath1522=== RUN TestClientErrorHandling/InvalidAuthToken1523=== PAUSE TestClientErrorHandling/InvalidAuthToken1524=== RUN TestClientErrorHandling/ServerNotAvailable1525=== PAUSE TestClientErrorHandling/ServerNotAvailable1526=== CONT TestClientCADerivations15272026/09/21 14:12:16 OK 20241026095416_initial_model.sql (58.34ms)15282026/09/21 14:12:16 OK 20251210153512_drop_unused_gin_index.sql (6.95ms)15292026/09/21 14:12:16 OK 20251218171726_add_pins.sql (8.81ms)15302026/09/21 14:12:16 OK 20260628120000_add_object_size_and_stats.sql (13.45ms)15312026/09/21 14:12:16 OK 20260905000000_add_claims.sql (13.7ms)15322026/09/21 14:12:16 OK 20260920000000_drop_claims.sql (25.26ms)15332026/09/21 14:12:16 goose: successfully migrated database to version: 2026092000000015342026/09/21 14:12:16 OK 1_commit_pending_closure.sql (1.67ms)15352026/09/21 14:12:16 OK 2_object_stats_trigger.sql (347.21µs)15362026/09/21 14:12:16 goose: up to current file version: 215372026/09/21 14:12:16 OK 20241026095416_initial_model.sql (69.16ms)15382026/09/21 14:12:16 OK 20251210153512_drop_unused_gin_index.sql (4.84ms)15392026/09/21 14:12:16 OK 20251218171726_add_pins.sql (22.39ms)15402026-09-21 14:12:16.270 UTC [68446] ERROR: relation "goose_db_version" does not exist at character 3615412026-09-21 14:12:16.270 UTC [68446] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15422026/09/21 14:12:16 INFO lead: acquired remote=192.0.2.1:123415432026/09/21 14:12:16 OK 20260628120000_add_object_size_and_stats.sql (19.3ms)15442026/09/21 14:12:16 OK 20260905000000_add_claims.sql (18.66ms)15452026/09/21 14:12:16 OK 20260920000000_drop_claims.sql (22.25ms)15462026/09/21 14:12:16 goose: successfully migrated database to version: 2026092000000015472026/09/21 14:12:16 OK 1_commit_pending_closure.sql (1.99ms)15482026/09/21 14:12:16 OK 2_object_stats_trigger.sql (250.71µs)15492026/09/21 14:12:16 goose: up to current file version: 215502026/09/21 14:12:16 OK 20241026095416_initial_model.sql (66.32ms)15512026/09/21 14:12:16 OK 20251210153512_drop_unused_gin_index.sql (6.64ms)15522026/09/21 14:12:16 OK 20251218171726_add_pins.sql (9.64ms)15532026/09/21 14:12:16 OK 20260628120000_add_object_size_and_stats.sql (15.86ms)15542026-09-21 14:12:16.416 UTC [68448] ERROR: relation "goose_db_version" does not exist at character 3615552026-09-21 14:12:16.416 UTC [68448] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15562026/09/21 14:12:16 OK 20260905000000_add_claims.sql (17.88ms)15572026/09/21 14:12:16 INFO lead: released remote=192.0.2.1:123415582026/09/21 14:12:16 OK 20260920000000_drop_claims.sql (17.32ms)15592026/09/21 14:12:16 goose: successfully migrated database to version: 2026092000000015602026/09/21 14:12:16 OK 1_commit_pending_closure.sql (1.82ms)15612026/09/21 14:12:16 OK 2_object_stats_trigger.sql (327.5µs)15622026/09/21 14:12:16 goose: up to current file version: 215632026/09/21 14:12:16 INFO lead: acquired remote=192.0.2.1:123415642026/09/21 14:12:16 INFO lead: released remote=192.0.2.1:12341565--- PASS: TestLeadElectsOneAndHandsOver (2.12s)1566=== CONT TestService_AuthMiddleware_MTLSBoundSubjects1567--- PASS: TestCacheStatsHandler (2.06s)1568=== CONT TestService_ReadAuthMiddleware15692026/09/21 14:12:16 OK 20241026095416_initial_model.sql (41.35ms)15702026/09/21 14:12:16 OK 20251210153512_drop_unused_gin_index.sql (5.29ms)1571=== NAME TestOrphanedObjectsGCStressTest1572 orphaned_objects_gc_test.go:509: Stress test completed successfully:1573 orphaned_objects_gc_test.go:510: - Active objects preserved: 201574 orphaned_objects_gc_test.go:511: - Objects deleted: 2101575 orphaned_objects_gc_test.go:512: - Total GC'd: 2101576--- PASS: TestOrphanedObjectsGCStressTest (7.46s)1577=== CONT TestService_ReadScope_PublicByDefault15782026/09/21 14:12:16 OK 20251218171726_add_pins.sql (25.13ms)15792026/09/21 14:12:16 OK 20260628120000_add_object_size_and_stats.sql (25.9ms)15802026/09/21 14:12:16 OK 20260905000000_add_claims.sql (16.65ms)15812026/09/21 14:12:16 OK 20260920000000_drop_claims.sql (15.05ms)15822026/09/21 14:12:16 goose: successfully migrated database to version: 2026092000000015832026/09/21 14:12:16 OK 1_commit_pending_closure.sql (1.64ms)15842026/09/21 14:12:16 OK 2_object_stats_trigger.sql (342.08µs)15852026/09/21 14:12:16 goose: up to current file version: 215862026-09-21 14:12:16.629 UTC [68456] ERROR: relation "goose_db_version" does not exist at character 3615872026-09-21 14:12:16.629 UTC [68456] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15882026/09/21 14:12:16 OK 20241026095416_initial_model.sql (83.08ms)15892026/09/21 14:12:16 OK 20251210153512_drop_unused_gin_index.sql (9.6ms)15902026/09/21 14:12:16 OK 20251218171726_add_pins.sql (26.75ms)15912026/09/21 14:12:16 OK 20260628120000_add_object_size_and_stats.sql (33.96ms)15922026/09/21 14:12:16 OK 20260905000000_add_claims.sql (68.74ms)15932026/09/21 14:12:16 OK 20260920000000_drop_claims.sql (50.82ms)15942026/09/21 14:12:16 goose: successfully migrated database to version: 2026092000000015952026/09/21 14:12:16 OK 1_commit_pending_closure.sql (3.23ms)15962026/09/21 14:12:16 OK 2_object_stats_trigger.sql (648.29µs)15972026/09/21 14:12:16 goose: up to current file version: 21598=== NAME TestPinProtectsFromGC1599 client_integration_test.go:731: Pinned store path: /nix/var/nix/builds/nix-68162-1667843226/TestPinProtectsFromGC774839437/001/store/sbavw69jqrwp1j3awwmpvl6r6m8h1nkh-pinned-file.txt1600 client_integration_test.go:732: Unpinned store path: /nix/var/nix/builds/nix-68162-1667843226/TestPinProtectsFromGC774839437/001/store/wabnq3zyhlyv1d78hlj5rkj30b74pxjw-unpinned-file.txt16012026/09/21 14:12:17 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"1602=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1603=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1604=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1605=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1606=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1607=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1608=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1609=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1610=== CONT TestCacheConfigHandler1611=== RUN TestCacheConfigHandler/full_config,_no_issuer1612=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1613=== RUN TestCacheConfigHandler/no_cache_url_configured1614=== PAUSE TestCacheConfigHandler/no_cache_url_configured1615=== RUN TestCacheConfigHandler/no_signing_keys1616=== PAUSE TestCacheConfigHandler/no_signing_keys1617=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1618=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1619=== CONT TestService_AuthMiddleware_MTLSProxyHeader16202026/09/21 14:12:17 INFO Received uploads request method=POST path=/api/pending_closures16212026/09/21 14:12:17 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)16222026/09/21 14:12:17 INFO Uploading sbavw69jqrwp1j3awwmpvl6r6m8h1nkh-pinned-file.txt (128B)16232026/09/21 14:12:17 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"16242026/09/21 14:12:17 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign16252026/09/21 14:12:17 WARN Failed to register uploaded object key=sbavw69jqrwp1j3awwmpvl6r6m8h1nkh.ls error="server returned 404: 404 page not found\n"16262026/09/21 14:12:17 INFO Signed narinfos id=1 count=116272026/09/21 14:12:17 INFO Uploading 1 narinfos16282026/09/21 14:12:17 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete16292026/09/21 14:12:17 WARN Failed to register uploaded object key=sbavw69jqrwp1j3awwmpvl6r6m8h1nkh.narinfo error="server returned 404: 404 page not found\n"16302026/09/21 14:12:17 INFO Completed upload id=116312026/09/21 14:12:17 INFO Upload complete. (225ms)16322026/09/21 14:12:17 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"16332026-09-21 14:12:17.286 UTC [68479] ERROR: relation "goose_db_version" does not exist at character 3616342026-09-21 14:12:17.286 UTC [68479] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16352026/09/21 14:12:17 INFO Received uploads request method=POST path=/api/pending_closures16362026/09/21 14:12:17 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"16372026-09-21 14:12:17.371 UTC [68484] ERROR: relation "goose_db_version" does not exist at character 3616382026-09-21 14:12:17.371 UTC [68484] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16392026/09/21 14:12:17 INFO Received uploads request method=POST path=/api/pending_closures16402026/09/21 14:12:17 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)16412026/09/21 14:12:17 INFO Uploading wabnq3zyhlyv1d78hlj5rkj30b74pxjw-unpinned-file.txt (128B)16422026/09/21 14:12:17 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"16432026/09/21 14:12:17 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign16442026/09/21 14:12:17 INFO Signed narinfos id=2 count=116452026/09/21 14:12:17 WARN Failed to register uploaded object key=wabnq3zyhlyv1d78hlj5rkj30b74pxjw.ls error="server returned 404: 404 page not found\n"16462026/09/21 14:12:17 INFO Uploading 1 narinfos16472026/09/21 14:12:17 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete16482026/09/21 14:12:17 WARN Failed to register uploaded object key=wabnq3zyhlyv1d78hlj5rkj30b74pxjw.narinfo error="server returned 404: 404 page not found\n"16492026/09/21 14:12:17 INFO Completed upload id=216502026/09/21 14:12:17 INFO Upload complete. (194ms)16512026/09/21 14:12:17 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"16522026/09/21 14:12:17 INFO Received create pin request method=POST path=/api/pins/myapp16532026/09/21 14:12:17 INFO Received uploads request method=POST path=/api/pending_closures16542026/09/21 14:12:17 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)16552026/09/21 14:12:17 INFO Uploading mjn5jls5b25dh1iirp4y373skla0vzrs-shared-dep (136B)16562026/09/21 14:12:17 INFO Created/updated pin name=myapp store_path=/nix/var/nix/builds/nix-68162-1667843226/TestPinProtectsFromGC774839437/001/store/sbavw69jqrwp1j3awwmpvl6r6m8h1nkh-pinned-file.txt narinfo_key=sbavw69jqrwp1j3awwmpvl6r6m8h1nkh.narinfo16572026/09/21 14:12:17 INFO Starting cleanup of old closures method=DELETE path=/api/closures16582026/09/21 14:12:17 INFO Garbage collection started16592026/09/21 14:12:17 INFO Aborted multipart uploads count=016602026/09/21 14:12:17 WARN Force mode enabled - objects will be deleted immediately without grace period16612026/09/21 14:12:17 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"16622026/09/21 14:12:17 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign16632026/09/21 14:12:17 INFO Signed narinfos id=2 count=116642026/09/21 14:12:17 WARN Failed to register uploaded object key=mjn5jls5b25dh1iirp4y373skla0vzrs.ls error="server returned 404: 404 page not found\n"16652026/09/21 14:12:17 INFO Uploading 1 narinfos16662026/09/21 14:12:17 OK 20241026095416_initial_model.sql (183.94ms)16672026/09/21 14:12:17 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete16682026/09/21 14:12:17 WARN Failed to register uploaded object key=mjn5jls5b25dh1iirp4y373skla0vzrs.narinfo error="server returned 404: 404 page not found\n"16692026/09/21 14:12:17 OK 20251210153512_drop_unused_gin_index.sql (4.31ms)16702026/09/21 14:12:17 OK 20251218171726_add_pins.sql (11.23ms)16712026/09/21 14:12:17 INFO Completed upload id=216722026/09/21 14:12:17 INFO Upload complete. (182ms)16732026/09/21 14:12:17 INFO Received uploads request method=POST path=/api/pending_closures16742026/09/21 14:12:17 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)16752026/09/21 14:12:17 INFO Uploading msa8lpv40zrqhsmiyy3cfrm7g8ikaygb-top (256B)16762026/09/21 14:12:17 INFO Uploading mjn5jls5b25dh1iirp4y373skla0vzrs-shared-dep (136B)16772026/09/21 14:12:17 OK 20241026095416_initial_model.sql (158.27ms)16782026/09/21 14:12:17 WARN Failed to register uploaded object key=nar/1py5nl1r4kk1inyzgm0w2wc8f3kfm7k0m281vp7rkmlx2w7pk1kx.nar.zst error="server returned 404: 404 page not found\n"16792026/09/21 14:12:17 OK 20260628120000_add_object_size_and_stats.sql (23.16ms)16802026/09/21 14:12:17 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"16812026/09/21 14:12:17 OK 20251210153512_drop_unused_gin_index.sql (2.2ms)16822026/09/21 14:12:17 WARN Failed to register uploaded object key=msa8lpv40zrqhsmiyy3cfrm7g8ikaygb.ls error="server returned 404: 404 page not found\n"16832026/09/21 14:12:17 OK 20260905000000_add_claims.sql (15.63ms)16842026/09/21 14:12:17 OK 20251218171726_add_pins.sql (14.41ms)16852026/09/21 14:12:17 INFO Received sign narinfos request method=POST path=/api/pending_closures/3/sign16862026/09/21 14:12:17 INFO Signed narinfos id=3 count=116872026/09/21 14:12:17 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign16882026/09/21 14:12:17 WARN Failed to register uploaded object key=mjn5jls5b25dh1iirp4y373skla0vzrs.ls error="server returned 404: 404 page not found\n"16892026/09/21 14:12:17 INFO Signed narinfos id=1 count=116902026/09/21 14:12:17 INFO Uploading 2 narinfos16912026/09/21 14:12:17 OK 20260920000000_drop_claims.sql (13.58ms)16922026/09/21 14:12:17 goose: successfully migrated database to version: 2026092000000016932026/09/21 14:12:17 WARN Failed to register uploaded object key=msa8lpv40zrqhsmiyy3cfrm7g8ikaygb.narinfo error="server returned 404: 404 page not found\n"16942026/09/21 14:12:17 OK 1_commit_pending_closure.sql (1.52ms)16952026/09/21 14:12:17 OK 2_object_stats_trigger.sql (237.92µs)16962026/09/21 14:12:17 goose: up to current file version: 216972026/09/21 14:12:17 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete16982026/09/21 14:12:17 WARN Failed to register uploaded object key=mjn5jls5b25dh1iirp4y373skla0vzrs.narinfo error="server returned 404: 404 page not found\n"16992026/09/21 14:12:17 INFO Completed upload id=117002026/09/21 14:12:17 INFO Received complete upload request method=POST path=/api/pending_closures/3/complete17012026/09/21 14:12:17 INFO Completed upload id=317022026/09/21 14:12:17 INFO Upload complete. (456ms)1703=== NAME TestClientSharedPathCommittedMidPush1704 client_integration_test.go:680: Retrieved narinfo from S3:1705 StorePath: /nix/var/nix/builds/nix-68162-1667843226/TestClientSharedPathCommittedMidPush3234190118/001/store/mjn5jls5b25dh1iirp4y373skla0vzrs-shared-dep1706 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1707 Compression: zstd1708 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821709 NarSize: 1361710 References: 1711 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1712 client_integration_test.go:680: Retrieved narinfo from S3:1713 StorePath: /nix/var/nix/builds/nix-68162-1667843226/TestClientSharedPathCommittedMidPush3234190118/001/store/msa8lpv40zrqhsmiyy3cfrm7g8ikaygb-top1714 URL: nar/1py5nl1r4kk1inyzgm0w2wc8f3kfm7k0m281vp7rkmlx2w7pk1kx.nar.zst1715 Compression: zstd1716 NarHash: sha256:1py5nl1r4kk1inyzgm0w2wc8f3kfm7k0m281vp7rkmlx2w7pk1kx1717 NarSize: 2561718 References: /nix/var/nix/builds/nix-68162-1667843226/TestClientSharedPathCommittedMidPush3234190118/001/store/mjn5jls5b25dh1iirp4y373skla0vzrs-shared-dep1719 CA: text:sha256:1zjfw6am7kih8d3rx7yk0pdbb6a2x3pr616zvndqvrxhzphvb70f17202026/09/21 14:12:17 OK 20260628120000_add_object_size_and_stats.sql (25.57ms)17212026/09/21 14:12:17 OK 20260905000000_add_claims.sql (53.37ms)1722--- PASS: TestClientSharedPathCommittedMidPush (2.63s)1723=== CONT TestService_RequireScope_OIDC17242026/09/21 14:12:17 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:61963/oidc17252026/09/21 14:12:17 OK 20260920000000_drop_claims.sql (33.53ms)17262026/09/21 14:12:17 goose: successfully migrated database to version: 2026092000000017272026/09/21 14:12:17 OK 1_commit_pending_closure.sql (1.11ms)17282026/09/21 14:12:17 OK 2_object_stats_trigger.sql (276.79µs)17292026/09/21 14:12:17 goose: up to current file version: 217302026/09/21 14:12:17 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=3 objects-deleted-after-grace-period=2001 objects-failed-to-delete=017312026/09/21 14:12:17 INFO Vacuumed table table=pending_closures17322026/09/21 14:12:17 INFO Vacuumed table table=pending_objects17332026/09/21 14:12:17 INFO Vacuumed table table=multipart_uploads1734=== NAME TestClientMultipleUploads1735 client_integration_test.go:358: Created store path 0: /nix/var/nix/builds/nix-68162-1667843226/TestClientMultipleUploads1246068446/001/store/kmpx3l2llfa0ispi79xs6n4pnizslhgc-test-file-0.txt17362026-09-21 14:12:17.793 UTC [68504] ERROR: relation "goose_db_version" does not exist at character 3617372026-09-21 14:12:17.793 UTC [68504] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1738=== NAME TestClientWithDependencies1739 client_integration_test.go:613: Built derivation: /nix/var/nix/builds/nix-68162-1667843226/TestClientWithDependencies1940029886/001/store/r14d9v4d4xnaz4z93akq40afffkwr9dj-test-script17402026/09/21 14:12:17 INFO Vacuumed table table=closures17412026-09-21 14:12:17.814 UTC [68507] ERROR: relation "goose_db_version" does not exist at character 3617422026-09-21 14:12:17.814 UTC [68507] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17432026/09/21 14:12:17 INFO Vacuumed table table=objects17442026-09-21 14:12:17.841 UTC [68510] ERROR: relation "goose_db_version" does not exist at character 3617452026-09-21 14:12:17.841 UTC [68510] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1746 client_integration_test.go:615: Found 1 dependencies (including self)1747=== NAME TestClientMultipleUploads1748 client_integration_test.go:358: Created store path 1: /nix/var/nix/builds/nix-68162-1667843226/TestClientMultipleUploads1246068446/001/store/nzzplvqk9ri3q9hylgfp71n7jq5pb70i-test-file-1.txt17492026/09/21 14:12:17 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"17502026/09/21 14:12:17 INFO Received uploads request method=POST path=/api/pending_closures17512026/09/21 14:12:17 OK 20241026095416_initial_model.sql (127.79ms)17522026/09/21 14:12:17 OK 20251210153512_drop_unused_gin_index.sql (11.89ms)17532026/09/21 14:12:17 OK 20241026095416_initial_model.sql (108.93ms)17542026/09/21 14:12:17 OK 20251218171726_add_pins.sql (9.83ms)1755 client_integration_test.go:358: Created store path 2: /nix/var/nix/builds/nix-68162-1667843226/TestClientMultipleUploads1246068446/001/store/4cxqphy1vdxwqmcpikmb5xjwijxx5kah-test-file-2.txt17562026/09/21 14:12:17 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)17572026/09/21 14:12:17 INFO Uploading r14d9v4d4xnaz4z93akq40afffkwr9dj-test-script (136B)17582026/09/21 14:12:17 OK 20251210153512_drop_unused_gin_index.sql (15.74ms)17592026/09/21 14:12:18 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"17602026/09/21 14:12:18 OK 20251218171726_add_pins.sql (16.71ms)17612026/09/21 14:12:18 WARN Failed to register uploaded object key=log/vaq28f4rp3xa6qwcgcnqmfww8krfz8y2-test-script.drv error="server returned 404: 404 page not found\n"17622026/09/21 14:12:18 OK 20260628120000_add_object_size_and_stats.sql (38.04ms)17632026/09/21 14:12:18 OK 20241026095416_initial_model.sql (125.12ms)17642026/09/21 14:12:18 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign17652026/09/21 14:12:18 OK 20251210153512_drop_unused_gin_index.sql (882.92µs)17662026/09/21 14:12:18 WARN Failed to register uploaded object key=r14d9v4d4xnaz4z93akq40afffkwr9dj.ls error="server returned 404: 404 page not found\n"17672026/09/21 14:12:18 INFO Signed narinfos id=1 count=117682026/09/21 14:12:18 INFO Uploading 1 narinfos17692026/09/21 14:12:18 OK 20260628120000_add_object_size_and_stats.sql (13.03ms)1770=== NAME TestClientIntegration1771 client_integration_test.go:286: Created store path: /nix/var/nix/builds/nix-68162-1667843226/TestClientIntegration71697823/002/store/hj6mpwj86mznnn6sqbngs7fjc33nkvj7-test-file.txt17722026/09/21 14:12:18 OK 20260905000000_add_claims.sql (15.54ms)17732026/09/21 14:12:18 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete17742026/09/21 14:12:18 WARN Failed to register uploaded object key=r14d9v4d4xnaz4z93akq40afffkwr9dj.narinfo error="server returned 404: 404 page not found\n"17752026/09/21 14:12:18 OK 20251218171726_add_pins.sql (21.14ms)17762026/09/21 14:12:18 OK 20260920000000_drop_claims.sql (17.55ms)17772026/09/21 14:12:18 goose: successfully migrated database to version: 2026092000000017782026/09/21 14:12:18 INFO Completed upload id=117792026/09/21 14:12:18 INFO Upload complete. (141ms)17802026/09/21 14:12:18 OK 1_commit_pending_closure.sql (1.27ms)17812026/09/21 14:12:18 OK 2_object_stats_trigger.sql (277.5µs)17822026/09/21 14:12:18 goose: up to current file version: 21783=== NAME TestClientWithDependencies1784 client_integration_test.go:617: Skipping nix copy test - isolated store (/nix/var/nix/builds/nix-68162-1667843226/TestClientWithDependencies1940029886/001/store) requires matching store prefix17852026/09/21 14:12:18 OK 20260905000000_add_claims.sql (34.2ms)17862026/09/21 14:12:18 OK 20260628120000_add_object_size_and_stats.sql (38.06ms)17872026/09/21 14:12:18 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"17882026/09/21 14:12:18 OK 20260920000000_drop_claims.sql (27.34ms)17892026/09/21 14:12:18 goose: successfully migrated database to version: 2026092000000017902026/09/21 14:12:18 OK 1_commit_pending_closure.sql (1.28ms)17912026/09/21 14:12:18 OK 2_object_stats_trigger.sql (266.83µs)17922026/09/21 14:12:18 goose: up to current file version: 21793--- PASS: TestClientWithDependencies (2.61s)1794=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info17952026/09/21 14:12:18 INFO Received uploads request method=POST path=/1796=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key17972026/09/21 14:12:18 INFO Received request for more parts method=POST path=/1798=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key17992026/09/21 14:12:18 INFO Received complete multipart upload request method=POST path=/1800=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal18012026/09/21 14:12:18 INFO Received uploads request method=POST path=/1802--- PASS: TestUploadHandlersRejectInvalidKeys (0.04s)1803 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1804 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1805 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1806 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1807=== CONT TestIsValidUploadKey/narinfo1808=== CONT TestIsValidUploadKey/nix-cache-info1809=== CONT TestProxyWriteTimeout/narinfo1810=== CONT TestIsValidUploadKey/build_log1811=== CONT TestIsValidUploadKey/listing1812=== CONT TestIsValidUploadKey/nar_plain1813=== CONT TestIsValidUploadKey/nar_xz1814=== CONT TestIsValidUploadKey/build_log_home-manager_file1815=== CONT TestIsValidUploadKey/realisation_plus_in_output1816=== CONT TestIsValidUploadKey/nar_zst1817=== CONT TestIsValidUploadKey/realisation1818=== CONT TestIsValidUploadKey/build_log_equals1819=== CONT TestIsValidUploadKey/build_log_question_mark1820=== CONT TestIsValidUploadKey/build_log_plus_in_name1821=== CONT TestIsValidUploadKey/traversal1822=== CONT TestIsValidUploadKey/unknown_type1823=== CONT TestIsValidUploadKey/empty_key1824=== CONT TestIsValidUploadKey/absolute1825=== CONT TestIsValidUploadKey/traversal_nar1826=== CONT TestProxyWriteTimeout/10_GiB_nar1827=== CONT TestProxyWriteTimeout/unknown_size1828=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1829=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1830=== CONT TestProxyWriteTimeout/1_GiB_nar1831--- PASS: TestProxyWriteTimeout (0.00s)1832 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1833 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1834 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1835 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1836=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1837=== CONT TestIsValidUploadKey/index.html1838--- PASS: TestIsValidUploadKey (0.03s)1839 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1840 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1841 --- PASS: TestIsValidUploadKey/build_log (0.00s)1842 --- PASS: TestIsValidUploadKey/listing (0.00s)1843 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1844 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1845 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1846 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1847 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1848 --- PASS: TestIsValidUploadKey/realisation (0.00s)1849 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1850 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1851 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1852 --- PASS: TestIsValidUploadKey/traversal (0.00s)1853 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1854 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1855 --- PASS: TestIsValidUploadKey/absolute (0.00s)1856 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1857 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1858 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1859 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1860 --- PASS: TestIsValidUploadKey/index.html (0.00s)1861=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure18622026/09/21 14:12:18 INFO Received uploads request method=POST path=/18632026/09/21 14:12:18 OK 20260905000000_add_claims.sql (21.78ms)18642026/09/21 14:12:18 OK 20260920000000_drop_claims.sql (1.66ms)18652026/09/21 14:12:18 goose: successfully migrated database to version: 2026092000000018662026/09/21 14:12:18 OK 1_commit_pending_closure.sql (1.22ms)18672026/09/21 14:12:18 OK 2_object_stats_trigger.sql (338.08µs)18682026/09/21 14:12:18 goose: up to current file version: 218692026/09/21 14:12:18 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"18702026/09/21 14:12:18 INFO Received uploads request method=POST path=/api/pending_closures18712026/09/21 14:12:18 INFO Received uploads request method=POST path=/api/pending_closures18722026/09/21 14:12:18 INFO Received uploads request method=POST path=/api/pending_closures18732026/09/21 14:12:18 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)18742026/09/21 14:12:18 INFO Uploading 4cxqphy1vdxwqmcpikmb5xjwijxx5kah-test-file-2.txt (160B)18752026/09/21 14:12:18 INFO Uploading kmpx3l2llfa0ispi79xs6n4pnizslhgc-test-file-0.txt (160B)18762026/09/21 14:12:18 INFO Uploading nzzplvqk9ri3q9hylgfp71n7jq5pb70i-test-file-1.txt (160B)18772026/09/21 14:12:18 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"18782026/09/21 14:12:18 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"18792026/09/21 14:12:18 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"18802026/09/21 14:12:18 WARN Failed to register uploaded object key=nzzplvqk9ri3q9hylgfp71n7jq5pb70i.ls error="server returned 404: 404 page not found\n"18812026/09/21 14:12:18 WARN Failed to register uploaded object key=4cxqphy1vdxwqmcpikmb5xjwijxx5kah.ls error="server returned 404: 404 page not found\n"18822026/09/21 14:12:18 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign18832026/09/21 14:12:18 WARN Failed to register uploaded object key=kmpx3l2llfa0ispi79xs6n4pnizslhgc.ls error="server returned 404: 404 page not found\n"18842026/09/21 14:12:18 INFO Signed narinfos id=1 count=118852026/09/21 14:12:18 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign18862026/09/21 14:12:18 INFO Signed narinfos id=2 count=118872026/09/21 14:12:18 INFO Received sign narinfos request method=POST path=/api/pending_closures/3/sign18882026/09/21 14:12:18 INFO Signed narinfos id=3 count=118892026/09/21 14:12:18 INFO Uploading 3 narinfos18902026/09/21 14:12:18 WARN Failed to register uploaded object key=4cxqphy1vdxwqmcpikmb5xjwijxx5kah.narinfo error="server returned 404: 404 page not found\n"18912026/09/21 14:12:18 WARN Failed to register uploaded object key=kmpx3l2llfa0ispi79xs6n4pnizslhgc.narinfo error="server returned 404: 404 page not found\n"18922026/09/21 14:12:18 INFO Received complete upload request method=POST path=/api/pending_closures/3/complete18932026/09/21 14:12:18 WARN Failed to register uploaded object key=nzzplvqk9ri3q9hylgfp71n7jq5pb70i.narinfo error="server returned 404: 404 page not found\n"18942026/09/21 14:12:18 INFO Received uploads request method=POST path=/api/pending_closures18952026/09/21 14:12:18 INFO Completed upload id=318962026/09/21 14:12:18 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete18972026/09/21 14:12:18 INFO Completed upload id=118982026/09/21 14:12:18 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete18992026/09/21 14:12:18 INFO Completed upload id=219002026/09/21 14:12:18 INFO Upload complete. (167ms)1901=== NAME TestClientMultipleUploads1902 client_integration_test.go:369: Uploaded 3 paths in 209.520167ms19032026/09/21 14:12:18 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)19042026/09/21 14:12:18 INFO Uploading hj6mpwj86mznnn6sqbngs7fjc33nkvj7-test-file.txt (152B)19052026/09/21 14:12:18 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"1906--- PASS: TestClientMultipleUploads (2.46s)1907=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart19082026/09/21 14:12:18 INFO Received complete multipart upload request method=POST path=/19092026/09/21 14:12:18 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign19102026/09/21 14:12:18 WARN Failed to register uploaded object key=hj6mpwj86mznnn6sqbngs7fjc33nkvj7.ls error="server returned 404: 404 page not found\n"19112026/09/21 14:12:18 INFO Signed narinfos id=1 count=119122026/09/21 14:12:18 INFO Uploading 1 narinfos19132026/09/21 14:12:18 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete19142026/09/21 14:12:18 WARN Failed to register uploaded object key=hj6mpwj86mznnn6sqbngs7fjc33nkvj7.narinfo error="server returned 404: 404 page not found\n"19152026-09-21 14:12:18.219 UTC [68537] ERROR: relation "goose_db_version" does not exist at character 3619162026-09-21 14:12:18.219 UTC [68537] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1917=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts19182026/09/21 14:12:18 INFO Received request for more parts method=POST path=/19192026/09/21 14:12:18 INFO Completed upload id=119202026/09/21 14:12:18 INFO Upload complete. (174ms)1921=== CONT TestIsValidCachePath/narinfo1922=== CONT TestIsValidCachePath/invalid_char_e1923=== CONT TestIsValidCachePath/traversal_in_middle1924=== CONT TestIsValidCachePath/traversal_parent1925=== CONT TestIsValidCachePath/invalid_char_u1926=== CONT TestIsValidCachePath/index.html1927=== CONT TestIsValidCachePath/nix-cache-info1928=== CONT TestIsValidCachePath/realisation1929=== CONT TestIsValidCachePath/log1930=== CONT TestIsValidCachePath/ls1931=== CONT TestIsValidCachePath/nar_uncompressed1932=== CONT TestIsValidCachePath/nar_bz21933=== CONT TestIsValidCachePath/nar_xz1934=== CONT TestIsValidCachePath/nar_zst1935=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1936=== CONT TestIsValidCachePath/leading_slash1937=== CONT TestIsValidCachePath/short_hash1938=== CONT TestIsValidCachePath/wrong_extension1939=== CONT TestIsValidCachePath/empty1940=== CONT TestIsValidCachePath/random_path1941--- PASS: TestIsValidCachePath (0.00s)1942 --- PASS: TestIsValidCachePath/narinfo (0.00s)1943 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1944 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1945 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1946 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1947 --- PASS: TestIsValidCachePath/index.html (0.00s)1948 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1949 --- PASS: TestIsValidCachePath/realisation (0.00s)1950 --- PASS: TestIsValidCachePath/log (0.00s)1951 --- PASS: TestIsValidCachePath/ls (0.00s)1952 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1953 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1954 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1955 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1956 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1957 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1958 --- PASS: TestIsValidCachePath/short_hash (0.00s)1959 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1960 --- PASS: TestIsValidCachePath/empty (0.00s)1961 --- PASS: TestIsValidCachePath/random_path (0.00s)1962=== CONT TestParseSingleRange/none1963=== CONT TestParseSingleRange/open-ended1964=== CONT TestParseSingleRange/start_far_past_EOF1965=== CONT TestParseSingleRange/start_past_EOF1966=== CONT TestParseSingleRange/single_byte1967=== CONT TestParseSingleRange/suffix_exceeds_size1968=== CONT TestParseSingleRange/suffix1969=== CONT TestParseSingleRange/end_clamped_to_size1970=== CONT TestParseSingleRange/malformed_both_empty1971=== CONT TestParseSingleRange/closed1972=== CONT TestParseSingleRange/malformed_end_before_start1973=== CONT TestParseSingleRange/multi-range_ignored1974=== CONT TestParseSingleRange/malformed_no_dash1975=== CONT TestParseSingleRange/unknown_unit1976--- PASS: TestParseSingleRange (0.00s)1977 --- PASS: TestParseSingleRange/none (0.00s)1978 --- PASS: TestParseSingleRange/open-ended (0.00s)1979 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1980 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1981 --- PASS: TestParseSingleRange/single_byte (0.00s)1982 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1983 --- PASS: TestParseSingleRange/suffix (0.00s)1984 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1985 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1986 --- PASS: TestParseSingleRange/closed (0.00s)1987 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1988 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1989 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1990 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1991=== CONT TestServerTLSConfig/no_client_CA1992=== CONT TestServerTLSConfig/not_a_PEM_file1993=== CONT TestServerTLSConfig/missing_CA_file1994--- PASS: TestServerTLSConfig (0.00s)1995 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1996 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)1997 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1998=== CONT TestResolveDBConnectionString/flag_wins1999=== CONT TestResolveDBConnectionString/PGHOST_allows_empty2000=== CONT TestResolveDBConnectionString/nothing_configured2001=== CONT TestResolveDBConnectionString/missing_file_is_an_error2002=== CONT TestResolveDBConnectionString/file_when_flag_empty2003=== CONT TestClientErrorHandling/InvalidStorePath2004--- PASS: TestResolveDBConnectionString (0.02s)2005 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)2006 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)2007 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)2008 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)2009 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)20102026/09/21 14:12:18 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"20112026/09/21 14:12:18 WARN mTLS auth: bound subjects configured but subject DN unavailable20122026/09/21 14:12:18 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"2013--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (1.76s)2014=== CONT TestClientErrorHandling/ServerNotAvailable20152026/09/21 14:12:18 OK 20241026095416_initial_model.sql (5.34ms)20162026/09/21 14:12:18 OK 20251210153512_drop_unused_gin_index.sql (1.04ms)20172026/09/21 14:12:18 OK 20251218171726_add_pins.sql (2.04ms)20182026/09/21 14:12:18 OK 20260628120000_add_object_size_and_stats.sql (2.01ms)20192026/09/21 14:12:18 OK 20260905000000_add_claims.sql (1.81ms)20202026/09/21 14:12:18 OK 20260920000000_drop_claims.sql (1.69ms)20212026/09/21 14:12:18 goose: successfully migrated database to version: 2026092000000020222026/09/21 14:12:18 OK 1_commit_pending_closure.sql (1.37ms)20232026/09/21 14:12:18 OK 2_object_stats_trigger.sql (376µs)20242026/09/21 14:12:18 goose: up to current file version: 220252026/09/21 14:12:18 INFO All 1 paths already cached2026=== NAME TestClientIntegration2027 client_integration_test.go:312: Retrieved narinfo from S3:2028 StorePath: /nix/var/nix/builds/nix-68162-1667843226/TestClientIntegration71697823/002/store/hj6mpwj86mznnn6sqbngs7fjc33nkvj7-test-file.txt2029 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst2030 Compression: zstd2031 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk12032 NarSize: 1522033 References: 2034 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk12035 client_integration_test.go:313: Retrieved .ls file from S3 (compressed size: 77 bytes)2036 client_integration_test.go:313: Decompressed .ls content (64 bytes):2037 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}2038 client_integration_test.go:316: Testing garbage collection...20392026/09/21 14:12:18 INFO Starting cleanup of old closures method=DELETE path=/api/closures20402026/09/21 14:12:18 INFO Garbage collection started20412026/09/21 14:12:18 INFO Aborted multipart uploads count=020422026/09/21 14:12:18 WARN Force mode enabled - objects will be deleted immediately without grace period20432026-09-21 14:12:18.344 UTC [68548] ERROR: relation "goose_db_version" does not exist at character 3620442026-09-21 14:12:18.344 UTC [68548] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC2045=== NAME TestClientCADerivations2046 client_ca_test.go:136: Built CA derivation: /nix/var/nix/builds/nix-68162-1667843226/TestClientCADerivations1298936435/001/store/mqn81261zm34b8j77gabr5v2m22qq1jd-ca-test2047--- PASS: TestUploadHandlersRejectOversizedBody (0.06s)2048 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.02s)2049 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.02s)2050 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.29s)2051=== CONT TestClientErrorHandling/InvalidAuthToken20522026/09/21 14:12:18 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/present2053--- PASS: TestService_ReadAuthMiddleware (1.91s)2054=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token20552026/09/21 14:12:18 OK 20241026095416_initial_model.sql (39.23ms)20562026/09/21 14:12:18 OK 20251210153512_drop_unused_gin_index.sql (866.25µs)2057=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected20582026/09/21 14:12:18 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]2059=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2060=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected20612026/09/21 14:12:18 WARN Authentication failed token_preview=eyJhbGciOi...i5NhLRrOww token_length=702 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]2062=== CONT TestCacheConfigHandler/full_config,_no_issuer2063=== CONT TestCacheConfigHandler/no_signing_keys2064=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator2065=== CONT TestCacheConfigHandler/no_cache_url_configured2066--- PASS: TestCacheConfigHandler (0.00s)2067 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)2068 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)2069 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)2070 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)20712026/09/21 14:12:18 OK 20251218171726_add_pins.sql (1.5ms)2072--- PASS: TestService_AuthMiddleware_OIDC (1.79s)2073 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)2074 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)2075 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)2076 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)20772026/09/21 14:12:18 OK 20260628120000_add_object_size_and_stats.sql (11.81ms)2078=== NAME TestClientCADerivations2079 client_ca_test.go:139: Found 1 dependencies (including self)20802026/09/21 14:12:18 OK 20260905000000_add_claims.sql (11.4ms)20812026/09/21 14:12:18 OK 20260920000000_drop_claims.sql (1.49ms)20822026/09/21 14:12:18 goose: successfully migrated database to version: 2026092000000020832026/09/21 14:12:18 OK 1_commit_pending_closure.sql (828.83µs)20842026/09/21 14:12:18 OK 2_object_stats_trigger.sql (225.54µs)20852026/09/21 14:12:18 goose: up to current file version: 220862026/09/21 14:12:18 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=214.782359ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2087--- PASS: TestService_ReadScope_PublicByDefault (2.01s)20882026/09/21 14:12:18 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"20892026/09/21 14:12:18 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=3 objects-deleted-after-grace-period=2001 objects-failed-to-delete=020902026/09/21 14:12:18 INFO Vacuumed table table=pending_closures20912026/09/21 14:12:18 INFO Vacuumed table table=pending_objects20922026/09/21 14:12:18 INFO Vacuumed table table=multipart_uploads20932026/09/21 14:12:18 INFO Received uploads request method=POST path=/api/pending_closures20942026/09/21 14:12:18 INFO Vacuumed table table=closures20952026/09/21 14:12:18 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)20962026/09/21 14:12:18 INFO Uploading mqn81261zm34b8j77gabr5v2m22qq1jd-ca-test (144B)20972026/09/21 14:12:18 INFO Vacuumed table table=objects20982026/09/21 14:12:18 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"20992026/09/21 14:12:18 WARN Failed to register uploaded object key=mqn81261zm34b8j77gabr5v2m22qq1jd.ls error="server returned 404: 404 page not found\n"21002026/09/21 14:12:18 WARN Failed to register uploaded object key=log/a54la21lf2bi3b84pcmmrsi7zsn138ax-ca-test.drv error="server returned 404: 404 page not found\n"21012026/09/21 14:12:18 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign21022026/09/21 14:12:18 INFO Signed narinfos id=1 count=121032026/09/21 14:12:18 INFO Uploading 1 narinfos21042026/09/21 14:12:18 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete21052026/09/21 14:12:18 WARN Failed to register uploaded object key=mqn81261zm34b8j77gabr5v2m22qq1jd.narinfo error="server returned 404: 404 page not found\n"21062026/09/21 14:12:18 INFO Completed upload id=121072026/09/21 14:12:18 INFO Upload complete. (142ms)2108=== NAME TestClientCADerivations2109 client_ca_test.go:180: Narinfo contains CA field: StorePath: /nix/var/nix/builds/nix-68162-1667843226/TestClientCADerivations1298936435/001/store/mqn81261zm34b8j77gabr5v2m22qq1jd-ca-test2110 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst2111 Compression: zstd2112 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n2113 NarSize: 1442114 References: 2115 Deriver: /nix/var/nix/builds/nix-68162-1667843226/TestClientCADerivations1298936435/001/store/a54la21lf2bi3b84pcmmrsi7zsn138ax-ca-test.drv2116 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n2117 client_ca_test.go:185: Checking for realisation files in S3...2118 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations2119 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache2120--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (1.58s)2121=== NAME TestClientCADerivations2122 client_ca_test.go:258: nix copy output: error: binary cache 's3://bucket49?endpoint=http://localhost:61836®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/nix/var/nix/builds/nix-68162-1667843226/TestClientCADerivations1298936435/001/store'2123 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 121242026-09-21 14:12:18.668 UTC [68564] ERROR: relation "goose_db_version" does not exist at character 3621252026-09-21 14:12:18.668 UTC [68564] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC2126--- PASS: TestClientCADerivations (2.54s)21272026/09/21 14:12:18 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=439.793038ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/objects/present21282026/09/21 14:12:18 OK 20241026095416_initial_model.sql (30.09ms)21292026/09/21 14:12:18 OK 20251210153512_drop_unused_gin_index.sql (1.04ms)21302026/09/21 14:12:18 OK 20251218171726_add_pins.sql (1.05ms)21312026/09/21 14:12:18 OK 20260628120000_add_object_size_and_stats.sql (13.68ms)21322026/09/21 14:12:18 OK 20260905000000_add_claims.sql (13.78ms)21332026/09/21 14:12:18 OK 20260920000000_drop_claims.sql (1.09ms)21342026/09/21 14:12:18 goose: successfully migrated database to version: 2026092000000021352026/09/21 14:12:18 OK 1_commit_pending_closure.sql (1.03ms)21362026/09/21 14:12:18 OK 2_object_stats_trigger.sql (240.54µs)21372026/09/21 14:12:18 goose: up to current file version: 221382026-09-21 14:12:18.820 UTC [68565] ERROR: relation "goose_db_version" does not exist at character 3621392026-09-21 14:12:18.820 UTC [68565] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC2140=== RUN TestService_RequireScope_OIDC/builder_may_write2141=== PAUSE TestService_RequireScope_OIDC/builder_may_write2142=== RUN TestService_RequireScope_OIDC/builder_may_not_admin2143=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin2144=== RUN TestService_RequireScope_OIDC/ops_may_admin2145=== PAUSE TestService_RequireScope_OIDC/ops_may_admin2146=== RUN TestService_RequireScope_OIDC/ops_may_not_write2147=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write2148=== RUN TestService_RequireScope_OIDC/reader_may_not_write2149=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write2150=== RUN TestService_RequireScope_OIDC/static_token_may_admin2151=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin2152=== RUN TestService_RequireScope_OIDC/static_token_may_write2153=== PAUSE TestService_RequireScope_OIDC/static_token_may_write2154=== RUN TestService_RequireScope_OIDC/reader_may_read2155=== PAUSE TestService_RequireScope_OIDC/reader_may_read2156=== RUN TestService_RequireScope_OIDC/writer_implies_read2157=== PAUSE TestService_RequireScope_OIDC/writer_implies_read2158=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read2159=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read2160=== CONT TestService_RequireScope_OIDC/builder_may_write2161=== CONT TestService_RequireScope_OIDC/static_token_may_admin2162=== CONT TestService_RequireScope_OIDC/writer_implies_read2163=== CONT TestService_RequireScope_OIDC/ops_may_not_write2164=== CONT TestService_RequireScope_OIDC/reader_may_read2165=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read2166=== CONT TestService_RequireScope_OIDC/static_token_may_write2167=== CONT TestService_RequireScope_OIDC/ops_may_admin2168=== CONT TestService_RequireScope_OIDC/reader_may_not_write2169=== CONT TestService_RequireScope_OIDC/builder_may_not_admin2170--- PASS: TestService_RequireScope_OIDC (1.14s)2171 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)2172 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)2173 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)2174 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)2175 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)2176 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)2177 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)2178 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)2179 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)2180 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)21812026/09/21 14:12:18 OK 20241026095416_initial_model.sql (24.71ms)21822026/09/21 14:12:18 OK 20251210153512_drop_unused_gin_index.sql (6.48ms)21832026/09/21 14:12:18 OK 20251218171726_add_pins.sql (5.18ms)21842026/09/21 14:12:18 OK 20260628120000_add_object_size_and_stats.sql (5.42ms)21852026/09/21 14:12:18 OK 20260905000000_add_claims.sql (10.15ms)21862026/09/21 14:12:18 OK 20260920000000_drop_claims.sql (6.93ms)21872026/09/21 14:12:18 goose: successfully migrated database to version: 2026092000000021882026/09/21 14:12:18 OK 1_commit_pending_closure.sql (1.65ms)21892026/09/21 14:12:18 OK 2_object_stats_trigger.sql (365.88µs)21902026/09/21 14:12:18 goose: up to current file version: 221912026/09/21 14:12:19 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"21922026/09/21 14:12:19 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"21932026/09/21 14:12:19 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=861.064443ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/objects/present21942026/09/21 14:12:19 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"21952026/09/21 14:12:19 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=02196=== NAME TestPinProtectsFromGC2197 client_integration_test.go:794: Pin successfully protected closure from garbage collection2198--- PASS: TestPinProtectsFromGC (4.69s)21992026/09/21 14:12:20 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.523583215s error="Post \"http://localhost:19999/api/objects/present\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/objects/present22002026/09/21 14:12:20 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=02201=== NAME TestClientIntegration2202 client_integration_test.go:323: Objects in database after GC:2203 client_integration_test.go:323: Successfully deleted all objects with GC --force2204--- PASS: TestClientIntegration (4.24s)22052026/09/21 14:12:21 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-config22062026/09/21 14:12:21 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=219.053617ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22072026/09/21 14:12:21 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=370.067107ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22082026/09/21 14:12:22 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=737.534709ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22092026/09/21 14:12:23 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.468426813s error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22102026/09/21 14:12:24 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"22112026/09/21 14:12:24 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_closures22122026/09/21 14:12:24 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=187.089991ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22132026/09/21 14:12:24 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=392.493798ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22142026/09/21 14:12:25 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=851.93262ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22152026/09/21 14:12:26 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.689259852s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2216--- PASS: TestClientErrorHandling (0.00s)2217 --- PASS: TestClientErrorHandling/InvalidStorePath (0.73s)2218 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.78s)2219 --- PASS: TestClientErrorHandling/ServerNotAvailable (9.60s)2220PASS2221{"timestamp":"2026-09-21T14:12:27.84838Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:61859","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(9)"}22222026-09-21 14:12:27.942 UTC [68203] LOG: received smart shutdown request22232026-09-21 14:12:27.943 UTC [68203] LOG: background worker "logical replication launcher" (PID 68213) exited with exit code 122242026-09-21 14:12:27.973 UTC [68208] LOG: shutting down22252026-09-21 14:12:27.973 UTC [68208] LOG: checkpoint starting: shutdown immediate22262026-09-21 14:12:29.049 UTC [68208] LOG: checkpoint complete: wrote 13200 buffers (80.6%), wrote 3 SLRU buffers; 0 WAL file(s) added, 0 removed, 16 recycled; write=0.727 s, sync=0.312 s, total=1.076 s; sync files=18738, longest=0.001 s, average=0.001 s; distance=260140 kB, estimate=260140 kB; lsn=0/11598098, redo lsn=0/1159809822272026-09-21 14:12:29.053 UTC [68203] LOG: database system is shut down2228Running OIDC tests...2229=== RUN TestGlobMatch2230=== PAUSE TestGlobMatch2231=== RUN TestAudienceForIssuer2232=== PAUSE TestAudienceForIssuer2233=== RUN TestValidateToken_ValidToken2234=== PAUSE TestValidateToken_ValidToken2235=== RUN TestValidateToken_WrongAudience2236=== PAUSE TestValidateToken_WrongAudience2237=== RUN TestValidateToken_Expired2238=== PAUSE TestValidateToken_Expired2239=== RUN TestValidateToken_BoundClaimsMismatch2240=== PAUSE TestValidateToken_BoundClaimsMismatch2241=== RUN TestValidateToken_BoundSubjectMismatch2242=== PAUSE TestValidateToken_BoundSubjectMismatch2243=== RUN TestValidateToken_MultipleProviders2244=== PAUSE TestValidateToken_MultipleProviders2245=== RUN TestValidateToken_NoMatchingProvider2246=== PAUSE TestValidateToken_NoMatchingProvider2247=== RUN TestValidateToken_KubernetesServiceAccount2248=== PAUSE TestValidateToken_KubernetesServiceAccount2249=== RUN TestNewValidator_KubernetesRequiresCA2250=== PAUSE TestNewValidator_KubernetesRequiresCA2251=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2252=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2253=== RUN TestScopes_LegacyProviderDefaultsToWrite2254=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2255=== RUN TestScopes_Rules2256=== PAUSE TestScopes_Rules2257=== RUN TestScopes_ConfigValidation2258=== PAUSE TestScopes_ConfigValidation2259=== CONT TestGlobMatch2260=== CONT TestValidateToken_Expired2261=== RUN TestGlobMatch/foo_foo2262=== PAUSE TestGlobMatch/foo_foo2263=== RUN TestGlobMatch/foo_bar2264=== PAUSE TestGlobMatch/foo_bar2265=== RUN TestGlobMatch/*_2266=== CONT TestValidateToken_NoMatchingProvider2267=== CONT TestValidateToken_WrongAudience2268=== CONT TestScopes_LegacyProviderDefaultsToWrite2269=== CONT TestValidateToken_ValidToken2270=== CONT TestScopes_ConfigValidation2271=== CONT TestScopes_Rules2272=== CONT TestNewValidator_KubernetesRequiresCA2273=== PAUSE TestGlobMatch/*_2274=== RUN TestGlobMatch/*_anything2275=== PAUSE TestGlobMatch/*_anything2276=== RUN TestGlobMatch/foo*_foo2277=== PAUSE TestGlobMatch/foo*_foo2278=== RUN TestGlobMatch/foo*_foobar2279=== PAUSE TestGlobMatch/foo*_foobar2280=== RUN TestGlobMatch/foo*_bar2281=== PAUSE TestGlobMatch/foo*_bar2282=== RUN TestGlobMatch/*bar_bar2283=== PAUSE TestGlobMatch/*bar_bar2284=== RUN TestGlobMatch/*bar_foobar2285=== PAUSE TestGlobMatch/*bar_foobar2286=== RUN TestGlobMatch/*bar_foo2287=== PAUSE TestGlobMatch/*bar_foo2288=== RUN TestGlobMatch/foo*bar_foobar2289=== PAUSE TestGlobMatch/foo*bar_foobar2290=== RUN TestGlobMatch/foo*bar_foo123bar2291=== PAUSE TestGlobMatch/foo*bar_foo123bar2292=== RUN TestGlobMatch/foo*bar_foobarbaz2293=== PAUSE TestGlobMatch/foo*bar_foobarbaz2294=== RUN TestGlobMatch/*/*_foo/bar2295=== PAUSE TestGlobMatch/*/*_foo/bar2296=== RUN TestGlobMatch/*/*_foo2297=== PAUSE TestGlobMatch/*/*_foo2298=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2299=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2300=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02301=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02302=== RUN TestGlobMatch/refs/*/main_refs/heads/main2303=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2304=== CONT TestAudienceForIssuer2305--- PASS: TestAudienceForIssuer (0.00s)2306=== CONT TestValidateToken_BoundSubjectMismatch2307=== RUN TestGlobMatch/fo?_foo2308=== PAUSE TestGlobMatch/fo?_foo2309=== RUN TestGlobMatch/fo?_fo2310=== PAUSE TestGlobMatch/fo?_fo2311=== RUN TestGlobMatch/fo?_fooo2312=== PAUSE TestGlobMatch/fo?_fooo2313=== RUN TestGlobMatch/?oo_foo2314=== PAUSE TestGlobMatch/?oo_foo2315=== RUN TestGlobMatch/?oo_boo2316=== PAUSE TestGlobMatch/?oo_boo2317=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2318=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2319=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2320=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2321=== CONT TestValidateToken_MultipleProviders23222026/09/21 14:12:29 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:62043/oidc23232026/09/21 14:12:29 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:62041/oidc23242026/09/21 14:12:29 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:62037/oidc23252026/09/21 14:12:29 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:62040/oidc2326--- PASS: TestScopes_ConfigValidation (0.00s)2327=== CONT TestValidateToken_KubernetesIssuerFromOwnToken23282026/09/21 14:12:29 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:62039/oidc23292026/09/21 14:12:29 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:62038/oidc23302026/09/21 14:12:29 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:62042/oidc23312026/09/21 14:12:29 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:62044/oidc2332--- PASS: TestValidateToken_WrongAudience (0.01s)2333=== CONT TestValidateToken_KubernetesServiceAccount2334--- PASS: TestValidateToken_NoMatchingProvider (0.01s)2335=== CONT TestValidateToken_BoundClaimsMismatch2336--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.01s)2337=== CONT TestGlobMatch/foo_foo2338=== CONT TestGlobMatch/foo*bar_foobarbaz2339=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2340=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2341=== CONT TestGlobMatch/?oo_boo2342=== CONT TestGlobMatch/?oo_foo2343=== CONT TestGlobMatch/fo?_fooo2344=== CONT TestGlobMatch/fo?_fo2345=== CONT TestGlobMatch/fo?_foo2346=== CONT TestGlobMatch/refs/*/main_refs/heads/main2347=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02348=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2349=== CONT TestGlobMatch/*/*_foo2350=== CONT TestGlobMatch/*/*_foo/bar2351=== CONT TestGlobMatch/foo*_foobar2352=== CONT TestGlobMatch/foo*bar_foo123bar2353=== CONT TestGlobMatch/foo*bar_foobar2354=== CONT TestGlobMatch/*bar_foo2355=== CONT TestGlobMatch/*bar_foobar2356=== CONT TestGlobMatch/*bar_bar2357=== CONT TestGlobMatch/foo*_bar2358=== CONT TestGlobMatch/*_2359=== CONT TestGlobMatch/foo*_foo2360=== CONT TestGlobMatch/*_anything2361=== CONT TestGlobMatch/foo_bar2362--- PASS: TestGlobMatch (0.00s)2363 --- PASS: TestGlobMatch/foo_foo (0.00s)2364 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2365 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2366 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2367 --- PASS: TestGlobMatch/?oo_boo (0.00s)2368 --- PASS: TestGlobMatch/?oo_foo (0.00s)2369 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2370 --- PASS: TestGlobMatch/fo?_fo (0.00s)2371 --- PASS: TestGlobMatch/fo?_foo (0.00s)2372 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2373 --- PASS: TestGlobMatch/refs/heads/*_refs/tags2026/09/21 14:12:29 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC1232374/v1.0 (0.00s)2375 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2376 --- PASS: TestGlobMatch/*/*_foo (0.00s)2377 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2378 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2379 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2380 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2381 --- PASS: TestGlobMatch/*bar_foo (0.00s)2382 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2383 --- PASS: TestGlobMatch/*bar_bar (0.00s)2384 --- PASS: TestGlobMatch/foo*_bar (0.00s)2385 --- PASS: TestGlobMatch/*_ (0.00s)2386 --- PASS: TestGlobMatch/foo*_foo (0.00s)2387 --- PASS: TestGlobMatch/*_anything (0.00s)2388 --- PASS: TestGlobMatch/foo_bar (0.00s)23892026/09/21 14:12:29 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:62046/oidc2390--- PASS: TestValidateToken_ValidToken (0.01s)2391--- PASS: TestValidateToken_Expired (0.01s)23922026/09/21 14:12:29 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:62059/oidc2393--- PASS: TestValidateToken_BoundSubjectMismatch (0.01s)2394--- PASS: TestValidateToken_MultipleProviders (0.01s)2395--- PASS: TestValidateToken_BoundClaimsMismatch (0.01s)23962026/09/21 14:12:29 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:620602397--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.01s)23982026/09/21 14:12:29 http: TLS handshake error from 127.0.0.1:62053: remote error: tls: bad certificate2399--- PASS: TestNewValidator_KubernetesRequiresCA (0.02s)2400--- PASS: TestScopes_Rules (0.02s)2401--- PASS: TestValidateToken_KubernetesServiceAccount (0.01s)2402PASS2403Running hook tests...2404=== RUN TestSendPathsEmpty2405=== PAUSE TestSendPathsEmpty2406=== RUN TestQueueEnqueueAndFetch2407=== PAUSE TestQueueEnqueueAndFetch2408=== RUN TestQueueDeduplication2409=== PAUSE TestQueueDeduplication2410=== RUN TestQueueRemove2411=== PAUSE TestQueueRemove2412=== RUN TestQueueFetchBatchLimit2413=== PAUSE TestQueueFetchBatchLimit2414=== RUN TestQueueRetryMovesToBack2415=== PAUSE TestQueueRetryMovesToBack2416=== RUN TestQueueFetchRemoveLifecycle2417=== PAUSE TestQueueFetchRemoveLifecycle2418=== RUN TestQueueConcurrentWriters2419=== PAUSE TestQueueConcurrentWriters2420=== RUN TestQueueRemoveLargeClosure2421=== PAUSE TestQueueRemoveLargeClosure2422=== RUN TestServerClientIntegration2423=== PAUSE TestServerClientIntegration2424=== RUN TestServerQueueError2425=== PAUSE TestServerQueueError2426=== RUN TestGetListenerSocketActivation2427 server_test.go:210: === RUN TestGetListenerSocketActivation2428 --- PASS: TestGetListenerSocketActivation (0.00s)2429 PASS2430 2431--- PASS: TestGetListenerSocketActivation (0.01s)2432=== RUN TestDrainIsolatesPoisonPath2433=== PAUSE TestDrainIsolatesPoisonPath2434=== RUN TestRunNotBlockedByPoisonHead2435=== PAUSE TestRunNotBlockedByPoisonHead2436=== RUN TestDrainGivesUpWhenServerDown2437=== PAUSE TestDrainGivesUpWhenServerDown2438=== RUN TestFailedPathPrunedByLaterClosure2439=== PAUSE TestFailedPathPrunedByLaterClosure2440=== RUN TestWorkerUploadsAndRemoves2441=== PAUSE TestWorkerUploadsAndRemoves2442=== RUN TestWorkerSkipsGCdPaths2443=== PAUSE TestWorkerSkipsGCdPaths2444=== RUN TestWorkerPrunesClosureDeps2445=== PAUSE TestWorkerPrunesClosureDeps2446=== RUN TestDrainTimeout2447=== PAUSE TestDrainTimeout2448=== CONT TestSendPathsEmpty2449=== CONT TestServerQueueError2450--- PASS: TestSendPathsEmpty (0.00s)2451=== CONT TestQueueRetryMovesToBack2452=== CONT TestQueueFetchBatchLimit2453=== CONT TestQueueRemove2454=== CONT TestQueueDeduplication2455=== CONT TestQueueEnqueueAndFetch2456=== CONT TestWorkerPrunesClosureDeps2457=== CONT TestDrainTimeout2458=== CONT TestDrainGivesUpWhenServerDown2459=== CONT TestWorkerUploadsAndRemoves24602026/09/21 14:12:30 ERROR Failed to queue paths error="permission denied" count=12461--- PASS: TestServerQueueError (0.00s)2462=== CONT TestFailedPathPrunedByLaterClosure24632026/09/21 14:12:30 INFO Upload queue status pending=224642026/09/21 14:12:30 INFO Uploading batch count=124652026/09/21 14:12:30 INFO Uploading batch count=224662026/09/21 14:12:30 INFO Uploading batch count=124672026/09/21 14:12:30 ERROR Upload failed error="upload failed" count=12468--- PASS: TestQueueRetryMovesToBack (0.01s)2469=== CONT TestQueueRemoveLargeClosure24702026/09/21 14:12:30 INFO Upload queue status pending=224712026/09/21 14:12:30 INFO Uploading batch count=22472--- PASS: TestQueueFetchBatchLimit (0.01s)2473=== CONT TestServerClientIntegration2474--- PASS: TestQueueEnqueueAndFetch (0.01s)2475=== CONT TestWorkerSkipsGCdPaths24762026/09/21 14:12:30 INFO Uploading batch count=224772026/09/21 14:12:30 ERROR Upload failed error="upload failed" count=224782026/09/21 14:12:30 INFO Uploading batch count=124792026/09/21 14:12:30 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-68162-1667843226/TestDrainGivesUpWhenServerDown2931743703/002/a24802026/09/21 14:12:30 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-68162-1667843226/TestDrainGivesUpWhenServerDown2931743703/002/b24812026/09/21 14:12:30 INFO Uploading batch count=12482--- PASS: TestQueueDeduplication (0.01s)2483=== CONT TestQueueFetchRemoveLifecycle24842026/09/21 14:12:30 INFO Uploading batch count=224852026/09/21 14:12:30 ERROR Upload failed error="upload failed" count=224862026/09/21 14:12:30 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-68162-1667843226/TestDrainGivesUpWhenServerDown2931743703/002/c2487--- PASS: TestQueueRemove (0.01s)2488=== CONT TestRunNotBlockedByPoisonHead2489--- PASS: TestServerClientIntegration (0.00s)2490=== CONT TestDrainIsolatesPoisonPath24912026/09/21 14:12:30 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-68162-1667843226/TestDrainGivesUpWhenServerDown2931743703/002/d24922026/09/21 14:12:30 INFO Uploading batch count=224932026/09/21 14:12:30 ERROR Upload failed error="upload failed" count=224942026/09/21 14:12:30 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-68162-1667843226/TestDrainGivesUpWhenServerDown2931743703/002/e24952026/09/21 14:12:30 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-68162-1667843226/TestDrainGivesUpWhenServerDown2931743703/002/f24962026/09/21 14:12:30 ERROR Drain finished with paths left in queue remaining=102497--- PASS: TestFailedPathPrunedByLaterClosure (0.01s)2498=== CONT TestQueueConcurrentWriters24992026/09/21 14:12:30 INFO Upload queue status pending=225002026/09/21 14:12:30 WARN Store path no longer exists (garbage collected?), removing from queue path=/nix/var/nix/builds/nix-68162-1667843226/TestWorkerSkipsGCdPaths3970581765/002/nonexistent25012026/09/21 14:12:30 INFO Uploading batch count=125022026/09/21 14:12:30 INFO Upload queue status pending=325032026/09/21 14:12:30 INFO Uploading batch count=125042026/09/21 14:12:30 ERROR Upload failed error="upload failed" count=125052026/09/21 14:12:30 INFO Uploading batch count=42506--- PASS: TestDrainGivesUpWhenServerDown (0.02s)25072026/09/21 14:12:30 ERROR Upload failed error="upload failed" count=42508--- PASS: TestQueueFetchRemoveLifecycle (0.00s)25092026/09/21 14:12:30 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-68162-1667843226/TestDrainIsolatesPoisonPath1112819221/002/bbb25102026/09/21 14:12:30 INFO Uploading batch count=125112026/09/21 14:12:30 ERROR Upload failed error="upload failed" count=125122026/09/21 14:12:30 INFO Uploading batch count=125132026/09/21 14:12:30 ERROR Upload failed error="upload failed" count=125142026/09/21 14:12:30 INFO Uploading batch count=125152026/09/21 14:12:30 ERROR Upload failed error="upload failed" count=125162026/09/21 14:12:30 ERROR Drain finished with paths left in queue remaining=12517--- PASS: TestDrainIsolatesPoisonPath (0.01s)2518--- PASS: TestWorkerPrunesClosureDeps (0.03s)2519--- PASS: TestWorkerUploadsAndRemoves (0.03s)2520--- PASS: TestWorkerSkipsGCdPaths (0.03s)2521--- PASS: TestQueueRemoveLargeClosure (0.05s)2522--- PASS: TestQueueConcurrentWriters (0.15s)25232026/09/21 14:12:30 ERROR Upload failed error="context deadline exceeded" count=225242026/09/21 14:12:30 ERROR Drain finished with paths left in queue remaining=42525--- PASS: TestDrainTimeout (0.21s)25262026/09/21 14:12:31 INFO Uploading batch count=125272026/09/21 14:12:31 INFO Uploading batch count=125282026/09/21 14:12:31 INFO Uploading batch count=125292026/09/21 14:12:31 ERROR Upload failed error="upload failed" count=125302026/09/21 14:12:31 INFO Uploading batch count=125312026/09/21 14:12:31 ERROR Upload failed error="upload failed" count=125322026/09/21 14:12:31 INFO Uploading batch count=125332026/09/21 14:12:31 ERROR Upload failed error="upload failed" count=125342026/09/21 14:12:31 INFO Uploading batch count=125352026/09/21 14:12:31 ERROR Upload failed error="upload failed" count=125362026/09/21 14:12:31 ERROR Drain finished with paths left in queue remaining=12537--- PASS: TestRunNotBlockedByPoisonHead (1.01s)2538PASS