niks3-go-unit-tests
checks.aarch64-darwin.go-unit-tests
· build #245
· 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.32s)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 TestSetClientTLSDoesNotMutateDefaultTransport92=== CONT TestStreamPushBatchesUnderLoad93=== CONT TestParsePathInfoJSON94=== RUN TestParsePathInfoJSON/Nix_format95=== PAUSE TestParsePathInfoJSON/Nix_format96=== RUN TestParsePathInfoJSON/Lix_format97=== CONT TestResolveStorePath98=== CONT TestSetClientTLS99=== CONT TestStreamPushRequestLine100=== CONT TestStreamPushGivesUpOnDeadServer101=== CONT TestStreamPushIsolatesFailures102=== CONT TestStreamPushReportsEveryPath103=== PAUSE TestParsePathInfoJSON/Lix_format1042026/09/22 08:42:55 ERROR Upload failed error="connection refused" count=201052026/09/22 08:42:55 ERROR Server seems unavailable, giving up on batch untried=17106=== RUN TestParsePathInfoJSON/empty_input1072026/09/22 08:42:55 ERROR Upload failed error="bad path" count=3108=== PAUSE TestParsePathInfoJSON/empty_input109=== RUN TestParsePathInfoJSON/whitespace_only110=== PAUSE TestParsePathInfoJSON/whitespace_only111=== RUN TestParsePathInfoJSON/invalid_JSON112=== PAUSE TestParsePathInfoJSON/invalid_JSON113=== CONT TestShellSplitErrors114--- PASS: TestShellSplitErrors (0.00s)115=== CONT TestShellSplit116--- PASS: TestResolveStorePath (0.00s)117--- PASS: TestShellSplit (0.00s)118=== CONT TestRateLimiterFeedback119=== RUN TestRateLimiterFeedback/429_enables_limiter120=== PAUSE TestRateLimiterFeedback/429_enables_limiter121=== RUN TestRateLimiterFeedback/503_enables_limiter122=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess123--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)124=== CONT TestScriptTokenNoExpiryRerunsEveryCall1252026/09/22 08:42:55 WARN Rate limiter enabled after throttle name=server-test rate=5126=== CONT TestDoWithRetry_BodyReplayedViaGetBody127=== PAUSE TestRateLimiterFeedback/503_enables_limiter128=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter129--- PASS: TestStreamPushIsolatesFailures (0.00s)130--- PASS: TestStreamPushReportsEveryPath (0.00s)131=== CONT TestScriptTokenEmptyCommand132--- PASS: TestScriptTokenEmptyCommand (0.00s)133=== CONT TestScriptTokenScriptFails1342026/09/22 08:42:55 ERROR Upload failed error=boom count=1135=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter136=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter137=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter138=== CONT TestScriptTokenBadJSON1392026/09/22 08:42:55 WARN Rate limiter enabled after throttle name=server-test rate=51402026/09/22 08:42:55 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:525721412026/09/22 08:42:55 WARN Rate limiter backed off name=server-test rate=51422026/09/22 08:42:55 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:52572143--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.00s)144=== CONT TestScriptTokenEmptyToken145--- PASS: TestDoServerRequestAttachesToken (0.01s)146=== CONT TestScriptTokenCachesUntilRefresh147--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.01s)148=== CONT TestDumpPathSingleFile149=== RUN TestSetClientTLS/rejects_connection_without_client_cert150=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert151=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA152--- PASS: TestScriptTokenScriptFails (0.01s)153=== CONT TestPathInfoHashCompatibility154=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)155=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)156=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon157=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon158=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI159=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI160=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512161=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512162=== CONT TestGetStorePathHash163=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA164=== RUN TestGetStorePathHash/valid_store_path165=== PAUSE TestGetStorePathHash/valid_store_path166=== RUN TestSetClientTLS/preserves_debug_logging_transport167=== PAUSE TestSetClientTLS/preserves_debug_logging_transport168=== RUN TestGetStorePathHash/basename_without_hyphen_should_error169=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error170=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error171=== CONT TestConvertHashToNix32172=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error173=== RUN TestConvertHashToNix32/SRI_format_to_Nix32174=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error175=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error176=== CONT TestEncodeNixBase32WithRealHash177=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32178--- PASS: TestEncodeNixBase32WithRealHash (0.00s)179=== RUN TestConvertHashToNix32/already_Nix32_format180=== CONT TestEncodeNixBase32181=== RUN TestEncodeNixBase32/test_string_hash182=== PAUSE TestEncodeNixBase32/test_string_hash183=== PAUSE TestConvertHashToNix32/already_Nix32_format184=== RUN TestEncodeNixBase32/empty_input185=== RUN TestConvertHashToNix32/invalid_format186=== PAUSE TestEncodeNixBase32/empty_input187=== CONT TestDumpPathWriterError188=== PAUSE TestConvertHashToNix32/invalid_format189=== CONT TestFileTokenReadsAndCaches190--- PASS: TestFileTokenReadsAndCaches (0.00s)191=== CONT TestFileTokenEmpty192--- PASS: TestFileTokenEmpty (0.00s)193=== CONT TestFileTokenMissing194--- PASS: TestFileTokenMissing (0.00s)195=== CONT TestPathInfoCACompatibility196=== RUN TestPathInfoCACompatibility/null_ca_field197=== PAUSE TestPathInfoCACompatibility/null_ca_field198=== RUN TestPathInfoCACompatibility/old_string_format_-_text199=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text200=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive201=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive202=== RUN TestPathInfoCACompatibility/new_structured_format_-_text203=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text204=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method205=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method206=== CONT TestParsePathInfoJSONMultiplePaths207=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths208=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths209=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths210=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths211=== CONT TestUploadMultipart_SupersededByPeer212=== RUN TestUploadMultipart_SupersededByPeer/exists213=== PAUSE TestUploadMultipart_SupersededByPeer/exists214=== RUN TestUploadMultipart_SupersededByPeer/missing215=== PAUSE TestUploadMultipart_SupersededByPeer/missing216=== CONT TestDumpPathMatchesNix217--- PASS: TestScriptTokenBadJSON (0.01s)218=== CONT TestStaticToken219--- PASS: TestStaticToken (0.00s)220=== CONT TestSetClientTLSErrors221=== RUN TestSetClientTLSErrors/missing_cert_file222=== PAUSE TestSetClientTLSErrors/missing_cert_file223=== RUN TestSetClientTLSErrors/missing_key_file224=== PAUSE TestSetClientTLSErrors/missing_key_file225=== RUN TestSetClientTLSErrors/missing_ca_file226=== PAUSE TestSetClientTLSErrors/missing_ca_file227=== RUN TestSetClientTLSErrors/invalid_ca_file228=== PAUSE TestSetClientTLSErrors/invalid_ca_file229=== CONT TestCaseHackSuffix230--- PASS: TestScriptTokenEmptyToken (0.01s)231=== CONT TestFilterOversizedClosures232=== RUN TestFilterOversizedClosures/no_limit_keeps_everything233=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything234=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped235=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped236=== RUN TestFilterOversizedClosures/all_closures_skipped237=== PAUSE TestFilterOversizedClosures/all_closures_skipped238=== CONT TestPartSizeForNAR239=== RUN TestPartSizeForNAR/zero_stays_at_minimum240=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum241=== RUN TestPartSizeForNAR/small_stays_at_minimum242=== PAUSE TestPartSizeForNAR/small_stays_at_minimum243=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum244=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum245=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts246=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts247=== RUN TestPartSizeForNAR/1_TiB248=== PAUSE TestPartSizeForNAR/1_TiB249=== RUN TestPartSizeForNAR/5_TiB_S3_max_object250=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object251=== RUN TestPartSizeForNAR/capped_at_5_GiB252=== PAUSE TestPartSizeForNAR/capped_at_5_GiB253=== CONT TestRegisterUploadedObjectReusesConnections254--- PASS: TestStreamPushRequestLine (0.02s)255=== CONT TestUploadMultipart_PartsInParallel256--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.04s)257=== CONT TestParsePathInfoJSON/Nix_format258=== CONT TestParsePathInfoJSON/whitespace_only259=== CONT TestParsePathInfoJSON/invalid_JSON260=== CONT TestParsePathInfoJSON/empty_input261=== CONT TestParsePathInfoJSON/Lix_format262--- PASS: TestParsePathInfoJSON (0.00s)263 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)264 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)265 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)266 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)267 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)268=== CONT TestRateLimiterFeedback/429_enables_limiter2692026/09/22 08:42:55 WARN Rate limiter enabled after throttle name=server-test rate=52702026/09/22 08:42:55 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:526472712026/09/22 08:42:55 WARN Rate limiter backed off name=server-test rate=5272=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter273=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter274=== CONT TestRateLimiterFeedback/503_enables_limiter275--- PASS: TestScriptTokenCachesUntilRefresh (0.04s)276=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)277=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI278=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512279=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon280--- PASS: TestPathInfoHashCompatibility (0.00s)281 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)282 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)283 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)284 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)285=== CONT TestSetClientTLS/rejects_connection_without_client_cert2862026/09/22 08:42:55 WARN Rate limiter enabled after throttle name=server-test rate=52872026/09/22 08:42:55 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:526532882026/09/22 08:42:55 WARN Rate limiter backed off name=server-test rate=5289--- PASS: TestRateLimiterFeedback (0.00s)290 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)291 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)292 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)293 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)294=== CONT TestSetClientTLS/preserves_debug_logging_transport295=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA296=== CONT TestGetStorePathHash/valid_store_path297=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error298=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error299=== CONT TestGetStorePathHash/basename_without_hyphen_should_error300=== CONT TestEncodeNixBase32/test_string_hash301=== CONT TestEncodeNixBase32/empty_input302=== CONT TestConvertHashToNix32/invalid_format303=== CONT TestConvertHashToNix32/SRI_format_to_Nix32304=== CONT TestConvertHashToNix32/already_Nix32_format305--- PASS: TestGetStorePathHash (0.00s)306 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)307 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)308 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)309 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)310=== CONT TestPathInfoCACompatibility/null_ca_field311=== CONT TestPathInfoCACompatibility/new_structured_format_-_text312--- PASS: TestConvertHashToNix32 (0.00s)313 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)314 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)315 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)316--- PASS: TestEncodeNixBase32 (0.00s)317 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)318 --- PASS: TestEncodeNixBase32/empty_input (0.00s)319=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method320=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths321=== CONT TestPathInfoCACompatibility/old_string_format_-_text322=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive323--- PASS: TestPathInfoCACompatibility (0.00s)324 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)325 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)326 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)327 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)328 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)329=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths330--- PASS: TestParsePathInfoJSONMultiplePaths (0.00s)331 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)332 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)333=== CONT TestUploadMultipart_SupersededByPeer/exists334--- PASS: TestRegisterUploadedObjectReusesConnections (0.04s)335=== CONT TestUploadMultipart_SupersededByPeer/missing336=== CONT TestSetClientTLSErrors/missing_cert_file337=== CONT TestSetClientTLSErrors/missing_ca_file338--- PASS: TestUploadMultipart_SupersededByPeer (0.00s)339 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)340 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)341=== CONT TestSetClientTLSErrors/invalid_ca_file342=== CONT TestSetClientTLSErrors/missing_key_file343=== CONT TestFilterOversizedClosures/no_limit_keeps_everything344=== CONT TestFilterOversizedClosures/all_closures_skipped3452026/09/22 08:42:55 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=50346=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped3472026/09/22 08:42:55 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=2000348--- PASS: TestFilterOversizedClosures (0.00s)349 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)350 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)351 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)352=== CONT TestPartSizeForNAR/zero_stays_at_minimum353=== CONT TestPartSizeForNAR/1_TiB354=== CONT TestPartSizeForNAR/5_TiB_S3_max_object355=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum356=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts357=== CONT TestPartSizeForNAR/small_stays_at_minimum358=== CONT TestPartSizeForNAR/capped_at_5_GiB359--- PASS: TestPartSizeForNAR (0.00s)360 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)361 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)362 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)363 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)364 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)365 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)366 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)367--- PASS: TestSetClientTLSErrors (0.00s)368 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)369 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)370 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)371 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)3722026/09/22 08:42:55 http: TLS handshake error from 127.0.0.1:52655: remote error: tls: bad certificate373--- PASS: TestSetClientTLS (0.01s)374 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.01s)375 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.00s)376 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.02s)377--- PASS: TestDumpPathWriterError (0.05s)378--- PASS: TestDumpPathSingleFile (0.06s)379--- PASS: TestCaseHackSuffix (0.05s)380--- PASS: TestDumpPathMatchesNix (0.08s)381--- PASS: TestStreamPushBatchesUnderLoad (0.10s)382--- PASS: TestUploadMultipart_PartsInParallel (0.61s)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-65797-4283757879/postgres1379289460/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-65797-4283757879/postgres1379289460/data -l logfile start412413/nix/var/nix/builds/nix-65797-4283757879/postgres1379289460:5432 - no response4142026-09-22 08:42:57.446 UTC [65876] LOG: starting PostgreSQL 18.6 on aarch64-apple-darwin25.6.0, compiled by clang version 21.1.8, 64-bit4152026-09-22 08:42:57.446 UTC [65876] LOG: listening on Unix socket "/nix/var/nix/builds/nix-65797-4283757879/postgres1379289460/.s.PGSQL.5432"4162026-09-22 08:42:57.448 UTC [65883] LOG: database system was shut down at 2026-09-22 08:42:57 UTC4172026-09-22 08:42:57.449 UTC [65876] LOG: database system is ready to accept connections418/nix/var/nix/builds/nix-65797-4283757879/postgres1379289460:5432 - accepting connections419{"timestamp":"2026-09-22T08:42:57.680219Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"15f733b9-eeef-4d36-87d6-ae02b7593894","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"GET","uri":"/health/ready","status_code":503,"suppressed_errors":0,"duration_ms":10,"result":"server_error","target":"rustfs::server::http","filename":"rustfs/src/server/layer.rs","line_number":463,"threadName":"rustfs-worker","threadId":"ThreadId(10)"}420{"timestamp":"2026-09-22T08:42:57.78638Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"658de3be-3822-49b5-a52a-c19f21f275a5","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"GET","uri":"/health/ready","status_code":503,"suppressed_errors":0,"duration_ms":0,"result":"server_error","target":"rustfs::server::http","filename":"rustfs/src/server/layer.rs","line_number":463,"threadName":"rustfs-worker","threadId":"ThreadId(6)"}421{"timestamp":"2026-09-22T08:42:57.889019Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"b02dde85-9340-4fa4-bcba-fba66c285577","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"GET","uri":"/health/ready","status_code":503,"suppressed_errors":0,"duration_ms":0,"result":"server_error","target":"rustfs::server::http","filename":"rustfs/src/server/layer.rs","line_number":463,"threadName":"rustfs-worker","threadId":"ThreadId(5)"}422=== RUN TestService_AuthMiddleware423=== PAUSE TestService_AuthMiddleware424=== RUN TestService_AuthMiddleware_MTLSProxyHeader425=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader426=== RUN TestService_AuthMiddleware_MTLSBoundSubjects427=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects428=== RUN TestService_ReadAuthMiddleware429=== PAUSE TestService_ReadAuthMiddleware430=== RUN TestService_AuthMiddleware_OIDC431=== PAUSE TestService_AuthMiddleware_OIDC432=== RUN TestService_RequireScope_OIDC433=== PAUSE TestService_RequireScope_OIDC434=== RUN TestService_ReadScope_PublicByDefault435=== PAUSE TestService_ReadScope_PublicByDefault436=== RUN TestCacheConfigHandler437=== PAUSE TestCacheConfigHandler438=== RUN TestCacheStatsHandler439=== PAUSE TestCacheStatsHandler440=== RUN TestClientCADerivations441=== PAUSE TestClientCADerivations442=== RUN TestClientErrorHandling443=== PAUSE TestClientErrorHandling444=== RUN TestClientIntegration445=== PAUSE TestClientIntegration446=== RUN TestClientMultipleUploads447=== PAUSE TestClientMultipleUploads448=== RUN TestClientWithDependencies449=== PAUSE TestClientWithDependencies450=== RUN TestClientSharedPathCommittedMidPush451=== PAUSE TestClientSharedPathCommittedMidPush452=== RUN TestPinProtectsFromGC453=== PAUSE TestPinProtectsFromGC454=== RUN TestResolveDBConnectionString455=== PAUSE TestResolveDBConnectionString456=== RUN TestLeadElectsOneAndHandsOver457=== PAUSE TestLeadElectsOneAndHandsOver458=== RUN TestLeadIncumbentWinsAfterRestart4592026-09-22 08:42:58.088 UTC [65915] ERROR: relation "goose_db_version" does not exist at character 364602026-09-22 08:42:58.088 UTC [65915] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC4612026/09/22 08:42:58 OK 20241026095416_initial_model.sql (3.22ms)4622026/09/22 08:42:58 OK 20251210153512_drop_unused_gin_index.sql (460.83µs)4632026/09/22 08:42:58 OK 20251218171726_add_pins.sql (776.46µs)4642026/09/22 08:42:58 OK 20260628120000_add_object_size_and_stats.sql (862.25µs)4652026/09/22 08:42:58 OK 20260905000000_add_claims.sql (859.79µs)4662026/09/22 08:42:58 OK 20260920000000_drop_claims.sql (589.33µs)4672026/09/22 08:42:58 goose: successfully migrated database to version: 202609200000004682026/09/22 08:42:58 OK 1_commit_pending_closure.sql (853.71µs)4692026/09/22 08:42:58 OK 2_object_stats_trigger.sql (191.38µs)4702026/09/22 08:42:58 goose: up to current file version: 24712026/09/22 08:42:58 INFO lead: acquired remote=192.0.2.1:12344722026/09/22 08:42:58 INFO lead: released remote=192.0.2.1:12344732026/09/22 08:42:58 INFO lead: acquired remote=192.0.2.1:12344742026/09/22 08:42:58 INFO lead: released remote=192.0.2.1:1234475--- PASS: TestLeadIncumbentWinsAfterRestart (0.82s)476=== RUN TestLeadEndsOnShutdown477=== PAUSE TestLeadEndsOnShutdown478=== RUN TestGCAdvisoryLockBlocksConcurrentRun4792026-09-22 08:42:58.864 UTC [65923] ERROR: relation "goose_db_version" does not exist at character 364802026-09-22 08:42:58.864 UTC [65923] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC4812026/09/22 08:42:58 OK 20241026095416_initial_model.sql (2.96ms)4822026/09/22 08:42:58 OK 20251210153512_drop_unused_gin_index.sql (459.04µs)4832026/09/22 08:42:58 OK 20251218171726_add_pins.sql (765.83µs)4842026/09/22 08:42:58 OK 20260628120000_add_object_size_and_stats.sql (758.54µs)4852026/09/22 08:42:58 OK 20260905000000_add_claims.sql (914.21µs)4862026/09/22 08:42:58 OK 20260920000000_drop_claims.sql (564.71µs)4872026/09/22 08:42:58 goose: successfully migrated database to version: 202609200000004882026/09/22 08:42:58 OK 1_commit_pending_closure.sql (811.96µs)4892026/09/22 08:42:58 OK 2_object_stats_trigger.sql (213.38µs)4902026/09/22 08:42:58 goose: up to current file version: 2491--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.12s)492=== RUN TestGCBugBareHashReferences493=== PAUSE TestGCBugBareHashReferences494=== RUN TestGCMetrics495=== PAUSE TestGCMetrics496=== RUN TestGCTaskStore_StartNew497=== PAUSE TestGCTaskStore_StartNew498=== RUN TestGCTaskStore_DeduplicateSameParams499=== PAUSE TestGCTaskStore_DeduplicateSameParams500=== RUN TestGCTaskStore_ConflictDifferentParams501=== PAUSE TestGCTaskStore_ConflictDifferentParams502=== RUN TestGCTaskStore_GetEmpty503=== PAUSE TestGCTaskStore_GetEmpty504=== RUN TestGCTaskStore_GetReturnsLatest505=== PAUSE TestGCTaskStore_GetReturnsLatest506=== RUN TestGCTaskStore_CompletedAllowsNewTask507=== PAUSE TestGCTaskStore_CompletedAllowsNewTask508=== RUN TestGCTaskStore_PhaseUpdates509=== PAUSE TestGCTaskStore_PhaseUpdates510=== RUN TestGCTaskStore_Fail511=== PAUSE TestGCTaskStore_Fail512=== RUN TestGracefulShutdownDrainsInflight513=== PAUSE TestGracefulShutdownDrainsInflight514=== RUN TestService_healthCheckHandler515=== PAUSE TestService_healthCheckHandler516=== RUN TestService_readinessHandler517=== PAUSE TestService_readinessHandler518=== RUN TestGenerateLandingPage519=== PAUSE TestGenerateLandingPage520=== RUN TestCacheConfigHandlerMaxNarSize521=== PAUSE TestCacheConfigHandlerMaxNarSize522=== RUN TestCreatePendingClosureRejectsOversizedNAR523=== PAUSE TestCreatePendingClosureRejectsOversizedNAR524=== RUN TestNARDeduplicationMetadataUploadBug525=== PAUSE TestNARDeduplicationMetadataUploadBug526=== RUN TestMetricsInventory527=== PAUSE TestMetricsInventory528=== RUN TestService_NativeMTLS529=== PAUSE TestService_NativeMTLS530=== RUN TestServerTLSConfig531=== PAUSE TestServerTLSConfig532=== RUN TestMultipartCleanup533=== PAUSE TestMultipartCleanup534=== RUN TestObjectStatsTrigger535=== PAUSE TestObjectStatsTrigger536=== RUN TestOrphanedObjectsGC537=== PAUSE TestOrphanedObjectsGC538=== RUN TestOrphanedObjectsGCStressTest539=== PAUSE TestOrphanedObjectsGCStressTest540=== RUN TestResurrectedObjectNotDeleted541=== PAUSE TestResurrectedObjectNotDeleted542=== RUN TestCreatePin_ReservedPins543=== PAUSE TestCreatePin_ReservedPins544=== RUN TestParseSingleRange545=== PAUSE TestParseSingleRange546=== RUN TestIsValidCachePath547=== PAUSE TestIsValidCachePath548=== RUN TestReadProxyNarinfo549=== PAUSE TestReadProxyNarinfo550=== RUN TestReadProxyNarinfoAlreadyDecompressed551=== PAUSE TestReadProxyNarinfoAlreadyDecompressed552=== RUN TestReadProxyNarStreaming553=== PAUSE TestReadProxyNarStreaming554=== RUN TestReadProxy404555=== PAUSE TestReadProxy404556=== RUN TestReadProxyInvalidPath557=== PAUSE TestReadProxyInvalidPath558=== RUN TestReadProxyHead559=== PAUSE TestReadProxyHead560=== RUN TestReadProxyConditionalGet561=== PAUSE TestReadProxyConditionalGet562=== RUN TestReadProxyRootRedirectsToIndexHTML563=== PAUSE TestReadProxyRootRedirectsToIndexHTML564=== RUN TestReadProxyDisabled565=== PAUSE TestReadProxyDisabled566=== RUN TestReadRedirectNar567=== PAUSE TestReadRedirectNar568=== RUN TestReadRedirectKeepsNarinfoProxied569=== PAUSE TestReadRedirectKeepsNarinfoProxied570=== RUN TestReadProxyRangeRequest571=== PAUSE TestReadProxyRangeRequest572=== RUN TestReadRedirectUsesPublicS3URL573=== PAUSE TestReadRedirectUsesPublicS3URL574=== RUN TestRedundantMultipartUpload575=== PAUSE TestRedundantMultipartUpload576=== RUN TestCompleteMultipartUpload_ErrorButObjectExists577=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists578=== RUN TestCompletedNarNotReofferedAcrossClosures579=== PAUSE TestCompletedNarNotReofferedAcrossClosures580=== RUN TestPresignedUploadRegisteredBeforeCommit581=== PAUSE TestPresignedUploadRegisteredBeforeCommit582=== RUN TestService_Rustfstest583=== PAUSE TestService_Rustfstest584=== RUN TestParseSize585=== PAUSE TestParseSize586=== RUN TestSkippedUploadsHandler587=== PAUSE TestSkippedUploadsHandler588=== RUN TestSystemdListenerNotActivated589--- PASS: TestSystemdListenerNotActivated (0.00s)590=== RUN TestWatchdogBeatsWhenHealthy591--- PASS: TestWatchdogBeatsWhenHealthy (0.03s)592=== RUN TestWatchdogSkipsWhenUnhealthy5932026/09/22 08:42:58 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5942026/09/22 08:42:59 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5952026/09/22 08:42:59 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5962026/09/22 08:42:59 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5972026/09/22 08:42:59 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5982026/09/22 08:42:59 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5992026/09/22 08:42:59 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6002026/09/22 08:42:59 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6012026/09/22 08:42:59 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6022026/09/22 08:42:59 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"603--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)604=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle605=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle606=== RUN TestProxyWriteTimeout607=== PAUSE TestProxyWriteTimeout608=== RUN TestIsValidUploadKey609=== PAUSE TestIsValidUploadKey610=== RUN TestUploadHandlersRejectInvalidKeys611=== PAUSE TestUploadHandlersRejectInvalidKeys612=== RUN TestUploadHandlersRejectOversizedBody613=== PAUSE TestUploadHandlersRejectOversizedBody614=== RUN TestService_cleanupPendingClosuresHandler615=== PAUSE TestService_cleanupPendingClosuresHandler616=== RUN TestService_createPendingClosureHandler617=== PAUSE TestService_createPendingClosureHandler618=== RUN TestService_verifyS3Integrity619=== PAUSE TestService_verifyS3Integrity620=== RUN TestCompleteMultipartUnregistered621=== PAUSE TestCompleteMultipartUnregistered622=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT623=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT624=== CONT TestUploadHandlersRejectOversizedBody625=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle626=== CONT TestService_verifyS3Integrity627=== CONT TestService_createPendingClosureHandler628=== CONT TestUploadHandlersRejectInvalidKeys629=== CONT TestIsValidUploadKey630=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info631=== RUN TestIsValidUploadKey/narinfo632=== PAUSE TestIsValidUploadKey/narinfo633=== CONT TestProxyWriteTimeout634=== CONT TestService_cleanupPendingClosuresHandler635=== RUN TestProxyWriteTimeout/narinfo636=== CONT TestCreatePendingClosureRejectsOversizedNAR637=== CONT TestService_AuthMiddleware638=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info639=== RUN TestIsValidUploadKey/nar_zst640=== PAUSE TestIsValidUploadKey/nar_zst641=== RUN TestIsValidUploadKey/nar_xz642=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal643=== PAUSE TestProxyWriteTimeout/narinfo644=== RUN TestProxyWriteTimeout/1_GiB_nar645=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal646=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key647=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key648=== PAUSE TestProxyWriteTimeout/1_GiB_nar649=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key650=== RUN TestProxyWriteTimeout/10_GiB_nar651=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key652=== PAUSE TestIsValidUploadKey/nar_xz653=== RUN TestIsValidUploadKey/nar_plain6542026/09/22 08:42:59 INFO Received uploads request method=POST path=/api/pending_closures655--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)656=== PAUSE TestProxyWriteTimeout/10_GiB_nar657=== PAUSE TestIsValidUploadKey/nar_plain658=== CONT TestSkippedUploadsHandler659=== RUN TestIsValidUploadKey/listing660=== PAUSE TestIsValidUploadKey/listing661=== RUN TestIsValidUploadKey/build_log662=== PAUSE TestIsValidUploadKey/build_log663=== RUN TestIsValidUploadKey/build_log_home-manager_file664=== RUN TestProxyWriteTimeout/unknown_size665=== PAUSE TestProxyWriteTimeout/unknown_size666=== PAUSE TestIsValidUploadKey/build_log_home-manager_file667=== RUN TestIsValidUploadKey/build_log_plus_in_name668=== PAUSE TestIsValidUploadKey/build_log_plus_in_name669=== RUN TestIsValidUploadKey/build_log_question_mark670=== PAUSE TestIsValidUploadKey/build_log_question_mark671=== RUN TestIsValidUploadKey/build_log_equals672=== PAUSE TestIsValidUploadKey/build_log_equals673=== RUN TestIsValidUploadKey/realisation674=== PAUSE TestIsValidUploadKey/realisation675=== RUN TestIsValidUploadKey/realisation_plus_in_output676=== CONT TestService_Rustfstest677=== PAUSE TestIsValidUploadKey/realisation_plus_in_output678=== RUN TestIsValidUploadKey/nix-cache-info679=== PAUSE TestIsValidUploadKey/nix-cache-info680=== RUN TestIsValidUploadKey/index.html681=== PAUSE TestIsValidUploadKey/index.html682=== RUN TestIsValidUploadKey/narinfo_key,_nar_type6832026/09/22 08:42:59 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000684=== CONT TestParseSize685--- PASS: TestParseSize (0.00s)686=== CONT TestPresignedUploadRegisteredBeforeCommit687=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type688=== RUN TestIsValidUploadKey/nar_key,_narinfo_type689=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type690=== RUN TestIsValidUploadKey/listing_key,_narinfo_type691=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type692=== RUN TestIsValidUploadKey/traversal693=== PAUSE TestIsValidUploadKey/traversal694=== RUN TestIsValidUploadKey/traversal_nar695=== PAUSE TestIsValidUploadKey/traversal_nar696=== RUN TestIsValidUploadKey/absolute697=== PAUSE TestIsValidUploadKey/absolute698=== RUN TestIsValidUploadKey/empty_key699=== PAUSE TestIsValidUploadKey/empty_key700=== RUN TestIsValidUploadKey/unknown_type701=== PAUSE TestIsValidUploadKey/unknown_type702=== CONT TestCompletedNarNotReofferedAcrossClosures703--- PASS: TestSkippedUploadsHandler (0.00s)704=== CONT TestCompleteMultipartUpload_ErrorButObjectExists705=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure706=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure707=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart708=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart709=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts710=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts711=== CONT TestRedundantMultipartUpload7122026-09-22 08:42:59.429 UTC [65945] ERROR: relation "goose_db_version" does not exist at character 367132026-09-22 08:42:59.429 UTC [65945] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7142026-09-22 08:42:59.443 UTC [65946] ERROR: relation "goose_db_version" does not exist at character 367152026-09-22 08:42:59.443 UTC [65946] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7162026-09-22 08:42:59.445 UTC [65947] ERROR: relation "goose_db_version" does not exist at character 367172026-09-22 08:42:59.445 UTC [65947] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7182026-09-22 08:42:59.447 UTC [65948] ERROR: relation "goose_db_version" does not exist at character 367192026-09-22 08:42:59.447 UTC [65948] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7202026-09-22 08:42:59.447 UTC [65949] ERROR: relation "goose_db_version" does not exist at character 367212026-09-22 08:42:59.447 UTC [65949] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7222026-09-22 08:42:59.448 UTC [65950] ERROR: relation "goose_db_version" does not exist at character 367232026-09-22 08:42:59.448 UTC [65950] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7242026/09/22 08:42:59 OK 20241026095416_initial_model.sql (12.24ms)7252026-09-22 08:42:59.449 UTC [65951] ERROR: relation "goose_db_version" does not exist at character 367262026-09-22 08:42:59.449 UTC [65951] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7272026-09-22 08:42:59.451 UTC [65952] ERROR: relation "goose_db_version" does not exist at character 367282026-09-22 08:42:59.451 UTC [65952] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7292026/09/22 08:42:59 OK 20251210153512_drop_unused_gin_index.sql (881.42µs)7302026-09-22 08:42:59.453 UTC [65953] ERROR: relation "goose_db_version" does not exist at character 367312026-09-22 08:42:59.453 UTC [65953] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7322026/09/22 08:42:59 OK 20251218171726_add_pins.sql (1.71ms)7332026-09-22 08:42:59.453 UTC [65954] ERROR: relation "goose_db_version" does not exist at character 367342026-09-22 08:42:59.453 UTC [65954] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7352026/09/22 08:42:59 OK 20260628120000_add_object_size_and_stats.sql (1.68ms)7362026/09/22 08:42:59 OK 20241026095416_initial_model.sql (7.78ms)7372026/09/22 08:42:59 OK 20260905000000_add_claims.sql (3.03ms)7382026/09/22 08:42:59 OK 20251210153512_drop_unused_gin_index.sql (736.88µs)7392026/09/22 08:42:59 OK 20241026095416_initial_model.sql (7.92ms)7402026/09/22 08:42:59 OK 20251218171726_add_pins.sql (1.24ms)7412026/09/22 08:42:59 OK 20241026095416_initial_model.sql (8.83ms)7422026/09/22 08:42:59 OK 20251210153512_drop_unused_gin_index.sql (900.25µs)7432026/09/22 08:42:59 OK 20260920000000_drop_claims.sql (2.15ms)7442026/09/22 08:42:59 goose: successfully migrated database to version: 202609200000007452026/09/22 08:42:59 OK 20241026095416_initial_model.sql (7.46ms)7462026/09/22 08:42:59 OK 20241026095416_initial_model.sql (8.68ms)7472026/09/22 08:42:59 OK 20251210153512_drop_unused_gin_index.sql (1.12ms)7482026/09/22 08:42:59 OK 20260628120000_add_object_size_and_stats.sql (1.4ms)7492026/09/22 08:42:59 OK 20251210153512_drop_unused_gin_index.sql (656.46µs)7502026/09/22 08:42:59 OK 20251210153512_drop_unused_gin_index.sql (785.21µs)7512026/09/22 08:42:59 OK 1_commit_pending_closure.sql (1.5ms)7522026/09/22 08:42:59 OK 20241026095416_initial_model.sql (8.24ms)7532026/09/22 08:42:59 OK 2_object_stats_trigger.sql (334.46µs)7542026/09/22 08:42:59 goose: up to current file version: 27552026/09/22 08:42:59 OK 20251218171726_add_pins.sql (1.96ms)7562026/09/22 08:42:59 OK 20251210153512_drop_unused_gin_index.sql (557.83µs)7572026/09/22 08:42:59 OK 20251218171726_add_pins.sql (1.66ms)7582026/09/22 08:42:59 OK 20241026095416_initial_model.sql (8.52ms)7592026/09/22 08:42:59 OK 20241026095416_initial_model.sql (6.4ms)7602026/09/22 08:42:59 OK 20251210153512_drop_unused_gin_index.sql (653.33µs)7612026/09/22 08:42:59 OK 20241026095416_initial_model.sql (6.89ms)7622026/09/22 08:42:59 OK 20251218171726_add_pins.sql (2.06ms)7632026/09/22 08:42:59 OK 20260628120000_add_object_size_and_stats.sql (1.58ms)7642026/09/22 08:42:59 OK 20251218171726_add_pins.sql (2.51ms)7652026/09/22 08:42:59 OK 20260905000000_add_claims.sql (2.99ms)7662026/09/22 08:42:59 OK 20251210153512_drop_unused_gin_index.sql (485.88µs)7672026/09/22 08:42:59 OK 20251210153512_drop_unused_gin_index.sql (778.46µs)7682026/09/22 08:42:59 OK 20251218171726_add_pins.sql (1.84ms)7692026/09/22 08:42:59 OK 20260628120000_add_object_size_and_stats.sql (2.27ms)7702026/09/22 08:42:59 OK 20251218171726_add_pins.sql (1.55ms)7712026/09/22 08:42:59 OK 20260905000000_add_claims.sql (3.77ms)7722026/09/22 08:42:59 OK 20260628120000_add_object_size_and_stats.sql (3.65ms)7732026/09/22 08:42:59 OK 20260628120000_add_object_size_and_stats.sql (3.97ms)7742026/09/22 08:42:59 OK 20260920000000_drop_claims.sql (54.95ms)7752026/09/22 08:42:59 goose: successfully migrated database to version: 202609200000007762026/09/22 08:42:59 OK 20260628120000_add_object_size_and_stats.sql (54.59ms)7772026/09/22 08:42:59 OK 20251218171726_add_pins.sql (55.43ms)7782026/09/22 08:42:59 OK 20260628120000_add_object_size_and_stats.sql (55.4ms)7792026/09/22 08:42:59 OK 20251218171726_add_pins.sql (55.7ms)7802026/09/22 08:42:59 OK 1_commit_pending_closure.sql (1.6ms)7812026/09/22 08:42:59 OK 2_object_stats_trigger.sql (224.96µs)7822026/09/22 08:42:59 goose: up to current file version: 27832026/09/22 08:42:59 OK 20260920000000_drop_claims.sql (60.62ms)7842026/09/22 08:42:59 goose: successfully migrated database to version: 202609200000007852026/09/22 08:42:59 OK 20260905000000_add_claims.sql (63.65ms)7862026/09/22 08:42:59 OK 20260628120000_add_object_size_and_stats.sql (8.75ms)7872026/09/22 08:42:59 OK 20260905000000_add_claims.sql (60.86ms)7882026/09/22 08:42:59 OK 20260905000000_add_claims.sql (61.18ms)7892026/09/22 08:42:59 OK 20260628120000_add_object_size_and_stats.sql (9.57ms)7902026/09/22 08:42:59 OK 20260905000000_add_claims.sql (9.64ms)7912026/09/22 08:42:59 OK 1_commit_pending_closure.sql (1.2ms)7922026/09/22 08:42:59 OK 2_object_stats_trigger.sql (237.67µs)7932026/09/22 08:42:59 goose: up to current file version: 27942026/09/22 08:42:59 OK 20260905000000_add_claims.sql (10.52ms)7952026/09/22 08:42:59 OK 20260920000000_drop_claims.sql (8.07ms)7962026/09/22 08:42:59 goose: successfully migrated database to version: 202609200000007972026/09/22 08:42:59 OK 20260920000000_drop_claims.sql (8.53ms)7982026/09/22 08:42:59 goose: successfully migrated database to version: 202609200000007992026/09/22 08:42:59 OK 20260920000000_drop_claims.sql (8.15ms)8002026/09/22 08:42:59 goose: successfully migrated database to version: 202609200000008012026/09/22 08:42:59 OK 20260920000000_drop_claims.sql (8.23ms)8022026/09/22 08:42:59 goose: successfully migrated database to version: 202609200000008032026/09/22 08:42:59 OK 1_commit_pending_closure.sql (1.08ms)8042026/09/22 08:42:59 OK 1_commit_pending_closure.sql (882.75µs)8052026/09/22 08:42:59 OK 2_object_stats_trigger.sql (281.17µs)8062026/09/22 08:42:59 goose: up to current file version: 28072026/09/22 08:42:59 OK 2_object_stats_trigger.sql (246.33µs)8082026/09/22 08:42:59 goose: up to current file version: 28092026/09/22 08:42:59 OK 1_commit_pending_closure.sql (1.17ms)8102026/09/22 08:42:59 OK 2_object_stats_trigger.sql (219.58µs)8112026/09/22 08:42:59 goose: up to current file version: 28122026/09/22 08:42:59 OK 1_commit_pending_closure.sql (879.96µs)8132026/09/22 08:42:59 OK 2_object_stats_trigger.sql (193.08µs)8142026/09/22 08:42:59 goose: up to current file version: 28152026/09/22 08:42:59 OK 20260920000000_drop_claims.sql (14.55ms)8162026/09/22 08:42:59 goose: successfully migrated database to version: 202609200000008172026/09/22 08:42:59 OK 20260905000000_add_claims.sql (16.6ms)8182026/09/22 08:42:59 OK 20260905000000_add_claims.sql (16.02ms)8192026/09/22 08:42:59 OK 1_commit_pending_closure.sql (926.29µs)8202026/09/22 08:42:59 OK 2_object_stats_trigger.sql (239.54µs)8212026/09/22 08:42:59 goose: up to current file version: 28222026/09/22 08:42:59 OK 20260920000000_drop_claims.sql (784.83µs)8232026/09/22 08:42:59 goose: successfully migrated database to version: 202609200000008242026/09/22 08:42:59 OK 20260920000000_drop_claims.sql (790.13µs)8252026/09/22 08:42:59 goose: successfully migrated database to version: 202609200000008262026/09/22 08:42:59 OK 1_commit_pending_closure.sql (821.21µs)8272026/09/22 08:42:59 OK 1_commit_pending_closure.sql (825.29µs)8282026/09/22 08:42:59 OK 2_object_stats_trigger.sql (201.33µs)8292026/09/22 08:42:59 goose: up to current file version: 28302026/09/22 08:42:59 OK 2_object_stats_trigger.sql (193.96µs)8312026/09/22 08:42:59 goose: up to current file version: 28322026/09/22 08:42:59 INFO Received uploads request method=POST path=/api/pending_closures8332026/09/22 08:42:59 INFO Received uploads request method=POST path=/api/pending_closures8342026/09/22 08:42:59 INFO Received uploads request method=POST path=/api/pending_closures8352026/09/22 08:42:59 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"836--- PASS: TestService_AuthMiddleware (0.54s)837=== CONT TestReadRedirectUsesPublicS3URL8382026/09/22 08:42:59 INFO Received uploads request method=POST path=/api/pending_closures8392026/09/22 08:43:00 INFO Received uploads request method=POST path=/api/pending_closures8402026/09/22 08:43:00 INFO Received complete multipart upload request method=POST path=/api/multipart/complete8412026/09/22 08:43:00 INFO Received complete multipart upload request method=POST path=/api/multipart/complete8422026/09/22 08:43:00 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=MzY3YzY3ZWEtMjY3OC00NTZmLWE3ZDYtZmQ0NTYxMjk2Yjk5LjI0YjFiYjA0LWFmOTMtNGYyMi04NGFkLTJiZDRmZWQxOGFhZXgxNzkwMDY2NTgwMTQ0MzE3MDAw8432026/09/22 08:43:00 INFO Received cleanup request method=DELETE path=/api/pending_closures8442026/09/22 08:43:00 INFO Aborted multipart uploads count=08452026/09/22 08:43:00 INFO Received uploads request method=POST path=/api/pending_closures8462026/09/22 08:43:00 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=MzY3YzY3ZWEtMjY3OC00NTZmLWE3ZDYtZmQ0NTYxMjk2Yjk5LjI0YjFiYjA0LWFmOTMtNGYyMi04NGFkLTJiZDRmZWQxOGFhZXgxNzkwMDY2NTgwMTQ0MzE3MDAw parts=1847--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (1.22s)848=== CONT TestReadProxyRangeRequest8492026/09/22 08:43:00 INFO Received cleanup request method=DELETE path=/api/pending_closures8502026/09/22 08:43:00 INFO Aborted multipart uploads count=18512026/09/22 08:43:00 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete8522026-09-22 08:43:00.464 UTC [65948] ERROR: Closure does not exist: id=18532026-09-22 08:43:00.464 UTC [65948] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 16 at RAISE8542026-09-22 08:43:00.464 UTC [65948] STATEMENT: -- name: CommitPendingClosure :exec855 SELECT commit_pending_closure($1::bigint)856 857--- PASS: TestService_cleanupPendingClosuresHandler (1.30s)858=== CONT TestReadRedirectKeepsNarinfoProxied8592026/09/22 08:43:00 INFO Received uploads request method=POST path=/api/pending_closures8602026/09/22 08:43:00 INFO Received complete multipart upload request method=POST path=/api/multipart/complete861--- PASS: TestService_Rustfstest (1.62s)862=== CONT TestReadRedirectNar8632026/09/22 08:43:00 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=MzY3YzY3ZWEtMjY3OC00NTZmLWE3ZDYtZmQ0NTYxMjk2Yjk5LmQzMzRkNmEyLTRlOGEtNGJmOS04N2Q0LThjYTFjMTY1OTdlOHgxNzkwMDY2NTc5NjA0NTU2MDAw parts=108642026/09/22 08:43:00 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete8652026/09/22 08:43:00 INFO Completed upload id=18662026/09/22 08:43:00 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000008672026/09/22 08:43:00 INFO Received uploads request method=POST path=/api/pending_closures8682026/09/22 08:43:00 INFO Starting cleanup of old closures method=DELETE path=/api/closures8692026/09/22 08:43:00 INFO Aborted multipart uploads count=08702026/09/22 08:43:00 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=08712026/09/22 08:43:00 INFO Vacuumed table table=pending_closures8722026/09/22 08:43:00 INFO Vacuumed table table=pending_objects8732026-09-22 08:43:00.886 UTC [65967] ERROR: relation "goose_db_version" does not exist at character 368742026-09-22 08:43:00.886 UTC [65967] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8752026/09/22 08:43:00 INFO Vacuumed table table=multipart_uploads8762026/09/22 08:43:00 INFO Vacuumed table table=closures8772026/09/22 08:43:00 INFO Vacuumed table table=objects8782026/09/22 08:43:00 INFO Received get closure request method=GET path=/api/closures/00000000000000000000000000000000879--- PASS: TestService_createPendingClosureHandler (1.77s)880=== CONT TestReadProxyDisabled8812026/09/22 08:43:01 INFO Received uploads request method=POST path=/api/pending_closures8822026/09/22 08:43:01 OK 20241026095416_initial_model.sql (129.49ms)8832026/09/22 08:43:01 OK 20251210153512_drop_unused_gin_index.sql (15.59ms)8842026/09/22 08:43:01 OK 20251218171726_add_pins.sql (27.53ms)8852026/09/22 08:43:01 OK 20260628120000_add_object_size_and_stats.sql (10.94ms)8862026/09/22 08:43:01 OK 20260905000000_add_claims.sql (26.18ms)8872026/09/22 08:43:01 OK 20260920000000_drop_claims.sql (43.14ms)8882026/09/22 08:43:01 goose: successfully migrated database to version: 202609200000008892026/09/22 08:43:01 OK 1_commit_pending_closure.sql (2.74ms)8902026/09/22 08:43:01 OK 2_object_stats_trigger.sql (687.38µs)8912026/09/22 08:43:01 goose: up to current file version: 28922026/09/22 08:43:01 INFO Received uploads request method=POST path=/api/pending_closures8932026/09/22 08:43:01 INFO Received uploads request method=POST path=/api/pending_closures8942026/09/22 08:43:01 INFO Received uploads request method=POST path=/api/pending_closures8952026-09-22 08:43:01.720 UTC [65970] ERROR: relation "goose_db_version" does not exist at character 368962026-09-22 08:43:01.720 UTC [65970] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8972026/09/22 08:43:01 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst8982026/09/22 08:43:01 INFO Received uploads request method=POST path=/api/pending_closures899--- PASS: TestPresignedUploadRegisteredBeforeCommit (2.53s)900=== CONT TestReadProxyRootRedirectsToIndexHTML9012026-09-22 08:43:01.811 UTC [65971] ERROR: relation "goose_db_version" does not exist at character 369022026-09-22 08:43:01.811 UTC [65971] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9032026/09/22 08:43:01 INFO Received complete multipart upload request method=POST path=/api/multipart/complete904--- PASS: TestReadRedirectUsesPublicS3URL (2.21s)905=== CONT TestReadProxyConditionalGet9062026/09/22 08:43:01 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=MzY3YzY3ZWEtMjY3OC00NTZmLWE3ZDYtZmQ0NTYxMjk2Yjk5LjJkNmYxNDgxLWY2OWMtNDVlZi05ZTJhLTBmNGNjZGY5MjQ1YngxNzkwMDY2NTgwNTg4ODgwMDAw parts=109072026/09/22 08:43:01 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete9082026/09/22 08:43:01 OK 20241026095416_initial_model.sql (182.58ms)9092026/09/22 08:43:02 INFO Completed upload id=19102026/09/22 08:43:02 OK 20251210153512_drop_unused_gin_index.sql (14.5ms)9112026/09/22 08:43:02 INFO Received uploads request method=POST path=/api/pending_closures9122026/09/22 08:43:02 INFO Received uploads request method=POST path=/api/pending_closures9132026/09/22 08:43:02 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo9142026/09/22 08:43:02 WARN Found objects in DB but missing from S3, will re-upload count=1915--- PASS: TestService_verifyS3Integrity (2.84s)916=== CONT TestReadProxyHead9172026/09/22 08:43:02 OK 20251218171726_add_pins.sql (36.92ms)9182026/09/22 08:43:02 OK 20241026095416_initial_model.sql (190.76ms)9192026/09/22 08:43:02 OK 20251210153512_drop_unused_gin_index.sql (7.04ms)9202026/09/22 08:43:02 OK 20260628120000_add_object_size_and_stats.sql (37.02ms)9212026/09/22 08:43:02 OK 20251218171726_add_pins.sql (10.1ms)9222026/09/22 08:43:02 OK 20260905000000_add_claims.sql (4.92ms)9232026/09/22 08:43:02 OK 20260920000000_drop_claims.sql (2.39ms)9242026/09/22 08:43:02 goose: successfully migrated database to version: 202609200000009252026/09/22 08:43:02 OK 1_commit_pending_closure.sql (2.24ms)9262026/09/22 08:43:02 OK 2_object_stats_trigger.sql (520.5µs)9272026/09/22 08:43:02 goose: up to current file version: 29282026/09/22 08:43:02 OK 20260628120000_add_object_size_and_stats.sql (29.78ms)9292026/09/22 08:43:02 OK 20260905000000_add_claims.sql (62.79ms)9302026-09-22 08:43:02.180 UTC [65979] ERROR: relation "goose_db_version" does not exist at character 369312026-09-22 08:43:02.180 UTC [65979] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9322026-09-22 08:43:02.180 UTC [65978] ERROR: relation "goose_db_version" does not exist at character 369332026-09-22 08:43:02.180 UTC [65978] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9342026/09/22 08:43:02 OK 20260920000000_drop_claims.sql (21.55ms)9352026/09/22 08:43:02 goose: successfully migrated database to version: 202609200000009362026/09/22 08:43:02 OK 1_commit_pending_closure.sql (3.47ms)9372026/09/22 08:43:02 OK 2_object_stats_trigger.sql (670.54µs)9382026/09/22 08:43:02 goose: up to current file version: 2939--- PASS: TestReadProxyRangeRequest (1.92s)940=== CONT TestReadProxyInvalidPath9412026/09/22 08:43:02 OK 20241026095416_initial_model.sql (143.81ms)9422026/09/22 08:43:02 OK 20241026095416_initial_model.sql (155.69ms)9432026/09/22 08:43:02 OK 20251210153512_drop_unused_gin_index.sql (11.46ms)9442026/09/22 08:43:02 OK 20251210153512_drop_unused_gin_index.sql (8.92ms)9452026/09/22 08:43:02 OK 20251218171726_add_pins.sql (22.35ms)9462026/09/22 08:43:02 OK 20251218171726_add_pins.sql (28.3ms)9472026/09/22 08:43:02 OK 20260628120000_add_object_size_and_stats.sql (36.36ms)9482026/09/22 08:43:02 OK 20260628120000_add_object_size_and_stats.sql (28.39ms)9492026/09/22 08:43:02 OK 20260905000000_add_claims.sql (46.54ms)9502026/09/22 08:43:02 OK 20260905000000_add_claims.sql (64.82ms)9512026/09/22 08:43:02 OK 20260920000000_drop_claims.sql (38.9ms)9522026/09/22 08:43:02 goose: successfully migrated database to version: 202609200000009532026/09/22 08:43:02 OK 1_commit_pending_closure.sql (2.72ms)9542026/09/22 08:43:02 OK 2_object_stats_trigger.sql (453.08µs)9552026/09/22 08:43:02 goose: up to current file version: 29562026/09/22 08:43:02 OK 20260920000000_drop_claims.sql (30ms)9572026/09/22 08:43:02 goose: successfully migrated database to version: 202609200000009582026/09/22 08:43:02 OK 1_commit_pending_closure.sql (1.97ms)9592026/09/22 08:43:02 OK 2_object_stats_trigger.sql (437.42µs)9602026/09/22 08:43:02 goose: up to current file version: 2961--- PASS: TestReadRedirectKeepsNarinfoProxied (2.11s)962=== CONT TestReadProxy4049632026/09/22 08:43:02 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9642026/09/22 08:43:02 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=MzY3YzY3ZWEtMjY3OC00NTZmLWE3ZDYtZmQ0NTYxMjk2Yjk5LmNmNDcwMTM3LTFmN2ItNGViOS1hY2I2LTJjYmZlNDA1MDIwNngxNzkwMDY2NTgxMDY0NDY3MDAw parts=129652026/09/22 08:43:02 INFO Received uploads request method=POST path=/api/pending_closures966--- PASS: TestCompletedNarNotReofferedAcrossClosures (3.48s)967=== CONT TestReadProxyNarStreaming968--- PASS: TestReadRedirectNar (2.02s)969=== CONT TestReadProxyNarinfoAlreadyDecompressed9702026/09/22 08:43:02 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9712026/09/22 08:43:02 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=MzY3YzY3ZWEtMjY3OC00NTZmLWE3ZDYtZmQ0NTYxMjk2Yjk5LjY4YTUyOTVmLTIzMGQtNDhkYi1hMDhkLWQ1Yjg3N2MzMGFlOXgxNzkwMDY2NTgxMjg2MTEzMDAw parts=12972--- PASS: TestRedundantMultipartUpload (3.74s)973=== CONT TestReadProxyNarinfo974--- PASS: TestReadProxyDisabled (2.12s)975=== CONT TestIsValidCachePath976=== RUN TestIsValidCachePath/narinfo977=== PAUSE TestIsValidCachePath/narinfo978=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars979=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars980=== RUN TestIsValidCachePath/nar_zst981=== PAUSE TestIsValidCachePath/nar_zst982=== RUN TestIsValidCachePath/nar_xz983=== PAUSE TestIsValidCachePath/nar_xz984=== RUN TestIsValidCachePath/nar_bz2985=== PAUSE TestIsValidCachePath/nar_bz2986=== RUN TestIsValidCachePath/nar_uncompressed987=== PAUSE TestIsValidCachePath/nar_uncompressed988=== RUN TestIsValidCachePath/ls989=== PAUSE TestIsValidCachePath/ls990=== RUN TestIsValidCachePath/log991=== PAUSE TestIsValidCachePath/log992=== RUN TestIsValidCachePath/realisation993=== PAUSE TestIsValidCachePath/realisation994=== RUN TestIsValidCachePath/nix-cache-info995=== PAUSE TestIsValidCachePath/nix-cache-info996=== RUN TestIsValidCachePath/index.html997=== PAUSE TestIsValidCachePath/index.html998=== RUN TestIsValidCachePath/traversal_parent999=== PAUSE TestIsValidCachePath/traversal_parent1000=== RUN TestIsValidCachePath/traversal_in_middle1001=== PAUSE TestIsValidCachePath/traversal_in_middle1002=== RUN TestIsValidCachePath/invalid_char_e1003=== PAUSE TestIsValidCachePath/invalid_char_e1004=== RUN TestIsValidCachePath/invalid_char_u1005=== PAUSE TestIsValidCachePath/invalid_char_u1006=== RUN TestIsValidCachePath/random_path1007=== PAUSE TestIsValidCachePath/random_path1008=== RUN TestIsValidCachePath/empty1009=== PAUSE TestIsValidCachePath/empty1010=== RUN TestIsValidCachePath/leading_slash1011=== PAUSE TestIsValidCachePath/leading_slash1012=== RUN TestIsValidCachePath/wrong_extension1013=== PAUSE TestIsValidCachePath/wrong_extension1014=== RUN TestIsValidCachePath/short_hash1015=== PAUSE TestIsValidCachePath/short_hash1016=== CONT TestParseSingleRange1017=== RUN TestParseSingleRange/none1018=== PAUSE TestParseSingleRange/none1019=== RUN TestParseSingleRange/unknown_unit1020=== PAUSE TestParseSingleRange/unknown_unit1021=== RUN TestParseSingleRange/multi-range_ignored1022=== PAUSE TestParseSingleRange/multi-range_ignored1023=== RUN TestParseSingleRange/malformed_no_dash1024=== PAUSE TestParseSingleRange/malformed_no_dash1025=== RUN TestParseSingleRange/malformed_both_empty1026=== PAUSE TestParseSingleRange/malformed_both_empty1027=== RUN TestParseSingleRange/malformed_end_before_start1028=== PAUSE TestParseSingleRange/malformed_end_before_start1029=== RUN TestParseSingleRange/closed1030=== PAUSE TestParseSingleRange/closed1031=== RUN TestParseSingleRange/open-ended1032=== PAUSE TestParseSingleRange/open-ended1033=== RUN TestParseSingleRange/end_clamped_to_size1034=== PAUSE TestParseSingleRange/end_clamped_to_size1035=== RUN TestParseSingleRange/suffix1036=== PAUSE TestParseSingleRange/suffix1037=== RUN TestParseSingleRange/suffix_exceeds_size1038=== PAUSE TestParseSingleRange/suffix_exceeds_size1039=== RUN TestParseSingleRange/single_byte1040=== PAUSE TestParseSingleRange/single_byte1041=== RUN TestParseSingleRange/start_past_EOF1042=== PAUSE TestParseSingleRange/start_past_EOF1043=== RUN TestParseSingleRange/start_far_past_EOF1044=== PAUSE TestParseSingleRange/start_far_past_EOF1045=== CONT TestCreatePin_ReservedPins10462026-09-22 08:43:03.112 UTC [65990] ERROR: relation "goose_db_version" does not exist at character 3610472026-09-22 08:43:03.112 UTC [65990] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10482026-09-22 08:43:03.133 UTC [65991] ERROR: relation "goose_db_version" does not exist at character 3610492026-09-22 08:43:03.133 UTC [65991] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10502026/09/22 08:43:03 OK 20241026095416_initial_model.sql (17.38ms)10512026/09/22 08:43:03 OK 20251210153512_drop_unused_gin_index.sql (401.58µs)10522026-09-22 08:43:03.145 UTC [65992] ERROR: relation "goose_db_version" does not exist at character 3610532026-09-22 08:43:03.145 UTC [65992] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10542026/09/22 08:43:03 OK 20251218171726_add_pins.sql (8.6ms)10552026/09/22 08:43:03 OK 20260628120000_add_object_size_and_stats.sql (8.7ms)10562026/09/22 08:43:03 OK 20260905000000_add_claims.sql (2.37ms)10572026/09/22 08:43:03 OK 20241026095416_initial_model.sql (11.1ms)10582026/09/22 08:43:03 OK 20251210153512_drop_unused_gin_index.sql (821.58µs)10592026/09/22 08:43:03 OK 20260920000000_drop_claims.sql (992.33µs)10602026/09/22 08:43:03 goose: successfully migrated database to version: 2026092000000010612026/09/22 08:43:03 OK 20251218171726_add_pins.sql (1.34ms)10622026/09/22 08:43:03 OK 1_commit_pending_closure.sql (1.43ms)10632026/09/22 08:43:03 OK 2_object_stats_trigger.sql (465.79µs)10642026/09/22 08:43:03 goose: up to current file version: 210652026/09/22 08:43:03 OK 20241026095416_initial_model.sql (9.53ms)10662026/09/22 08:43:03 OK 20251210153512_drop_unused_gin_index.sql (366.33µs)10672026/09/22 08:43:03 OK 20260628120000_add_object_size_and_stats.sql (2.78ms)10682026/09/22 08:43:03 OK 20251218171726_add_pins.sql (1.46ms)10692026/09/22 08:43:03 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:52718/oidc10702026/09/22 08:43:03 OK 20260628120000_add_object_size_and_stats.sql (22.41ms)10712026/09/22 08:43:03 OK 20260905000000_add_claims.sql (22.83ms)10722026/09/22 08:43:03 OK 20260920000000_drop_claims.sql (13.76ms)10732026/09/22 08:43:03 goose: successfully migrated database to version: 2026092000000010742026/09/22 08:43:03 OK 20260905000000_add_claims.sql (14.91ms)10752026/09/22 08:43:03 OK 1_commit_pending_closure.sql (1.77ms)10762026/09/22 08:43:03 OK 2_object_stats_trigger.sql (269.17µs)10772026/09/22 08:43:03 goose: up to current file version: 210782026/09/22 08:43:03 OK 20260920000000_drop_claims.sql (11.07ms)10792026/09/22 08:43:03 goose: successfully migrated database to version: 2026092000000010802026/09/22 08:43:03 OK 1_commit_pending_closure.sql (1.15ms)10812026/09/22 08:43:03 OK 2_object_stats_trigger.sql (248.79µs)10822026/09/22 08:43:03 goose: up to current file version: 21083--- PASS: TestReadProxyRootRedirectsToIndexHTML (1.57s)1084=== CONT TestResurrectedObjectNotDeleted1085--- PASS: TestReadProxyHead (1.46s)1086=== CONT TestOrphanedObjectsGCStressTest1087--- PASS: TestReadProxyConditionalGet (1.77s)1088=== CONT TestOrphanedObjectsGC10892026-09-22 08:43:03.740 UTC [66001] ERROR: relation "goose_db_version" does not exist at character 3610902026-09-22 08:43:03.740 UTC [66001] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10912026-09-22 08:43:03.747 UTC [66000] ERROR: relation "goose_db_version" does not exist at character 3610922026-09-22 08:43:03.747 UTC [66000] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10932026-09-22 08:43:03.759 UTC [66003] ERROR: relation "goose_db_version" does not exist at character 3610942026-09-22 08:43:03.759 UTC [66003] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10952026-09-22 08:43:03.762 UTC [66004] ERROR: relation "goose_db_version" does not exist at character 3610962026-09-22 08:43:03.762 UTC [66004] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10972026-09-22 08:43:03.765 UTC [66005] ERROR: relation "goose_db_version" does not exist at character 3610982026-09-22 08:43:03.765 UTC [66005] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10992026/09/22 08:43:03 OK 20241026095416_initial_model.sql (20.5ms)11002026/09/22 08:43:03 OK 20241026095416_initial_model.sql (18.43ms)11012026/09/22 08:43:03 OK 20241026095416_initial_model.sql (18.66ms)11022026/09/22 08:43:03 OK 20251210153512_drop_unused_gin_index.sql (953.79µs)11032026/09/22 08:43:03 OK 20251210153512_drop_unused_gin_index.sql (873.25µs)11042026/09/22 08:43:03 OK 20251210153512_drop_unused_gin_index.sql (988.88µs)11052026/09/22 08:43:03 OK 20251218171726_add_pins.sql (2.22ms)11062026/09/22 08:43:03 OK 20251218171726_add_pins.sql (2.41ms)11072026/09/22 08:43:03 OK 20251218171726_add_pins.sql (2.6ms)11082026/09/22 08:43:03 OK 20241026095416_initial_model.sql (17.32ms)11092026/09/22 08:43:03 OK 20241026095416_initial_model.sql (14.08ms)11102026/09/22 08:43:03 OK 20251210153512_drop_unused_gin_index.sql (758.38µs)11112026/09/22 08:43:03 OK 20251210153512_drop_unused_gin_index.sql (733.92µs)11122026/09/22 08:43:03 OK 20260628120000_add_object_size_and_stats.sql (7.19ms)11132026/09/22 08:43:03 OK 20251218171726_add_pins.sql (6.28ms)11142026/09/22 08:43:03 OK 20260628120000_add_object_size_and_stats.sql (7.57ms)11152026/09/22 08:43:03 OK 20251218171726_add_pins.sql (5.98ms)11162026/09/22 08:43:03 OK 20260628120000_add_object_size_and_stats.sql (7.19ms)11172026/09/22 08:43:03 OK 20260905000000_add_claims.sql (13.55ms)11182026/09/22 08:43:03 OK 20260905000000_add_claims.sql (13.69ms)11192026/09/22 08:43:03 OK 20260920000000_drop_claims.sql (1.5ms)11202026/09/22 08:43:03 goose: successfully migrated database to version: 2026092000000011212026/09/22 08:43:03 OK 20260920000000_drop_claims.sql (1.64ms)11222026/09/22 08:43:03 goose: successfully migrated database to version: 2026092000000011232026/09/22 08:43:03 OK 20260628120000_add_object_size_and_stats.sql (15.69ms)11242026/09/22 08:43:03 OK 20260628120000_add_object_size_and_stats.sql (15.93ms)11252026/09/22 08:43:03 OK 20260905000000_add_claims.sql (16.6ms)11262026/09/22 08:43:03 OK 1_commit_pending_closure.sql (1.72ms)11272026/09/22 08:43:03 OK 2_object_stats_trigger.sql (537.38µs)11282026/09/22 08:43:03 goose: up to current file version: 211292026/09/22 08:43:03 OK 1_commit_pending_closure.sql (2.22ms)11302026/09/22 08:43:03 OK 2_object_stats_trigger.sql (557.92µs)11312026/09/22 08:43:03 goose: up to current file version: 211322026/09/22 08:43:03 OK 20260920000000_drop_claims.sql (1.53ms)11332026/09/22 08:43:03 goose: successfully migrated database to version: 2026092000000011342026/09/22 08:43:03 OK 20260905000000_add_claims.sql (2.75ms)11352026/09/22 08:43:03 OK 20260905000000_add_claims.sql (3.1ms)11362026/09/22 08:43:03 OK 1_commit_pending_closure.sql (1.58ms)11372026/09/22 08:43:03 OK 20260920000000_drop_claims.sql (1.22ms)11382026/09/22 08:43:03 goose: successfully migrated database to version: 2026092000000011392026/09/22 08:43:03 OK 20260920000000_drop_claims.sql (1.21ms)11402026/09/22 08:43:03 goose: successfully migrated database to version: 2026092000000011412026/09/22 08:43:03 OK 2_object_stats_trigger.sql (335.67µs)11422026/09/22 08:43:03 goose: up to current file version: 211432026/09/22 08:43:03 OK 1_commit_pending_closure.sql (1.09ms)11442026/09/22 08:43:03 OK 1_commit_pending_closure.sql (994.83µs)11452026/09/22 08:43:03 OK 2_object_stats_trigger.sql (258.71µs)11462026/09/22 08:43:03 goose: up to current file version: 211472026/09/22 08:43:03 OK 2_object_stats_trigger.sql (268.25µs)11482026/09/22 08:43:03 goose: up to current file version: 21149--- PASS: TestReadProxyInvalidPath (1.62s)1150=== CONT TestObjectStatsTrigger1151--- PASS: TestReadProxy404 (1.57s)1152=== CONT TestMultipartCleanup11532026-09-22 08:43:04.208 UTC [66010] ERROR: relation "goose_db_version" does not exist at character 3611542026-09-22 08:43:04.208 UTC [66010] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11552026-09-22 08:43:04.257 UTC [66011] ERROR: relation "goose_db_version" does not exist at character 3611562026-09-22 08:43:04.257 UTC [66011] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11572026/09/22 08:43:04 OK 20241026095416_initial_model.sql (98.83ms)11582026/09/22 08:43:04 OK 20251210153512_drop_unused_gin_index.sql (7.59ms)1159--- PASS: TestReadProxyNarinfoAlreadyDecompressed (1.52s)1160=== CONT TestServerTLSConfig1161=== RUN TestServerTLSConfig/no_client_CA1162=== PAUSE TestServerTLSConfig/no_client_CA1163=== RUN TestServerTLSConfig/missing_CA_file1164=== PAUSE TestServerTLSConfig/missing_CA_file1165=== RUN TestServerTLSConfig/not_a_PEM_file1166=== PAUSE TestServerTLSConfig/not_a_PEM_file1167=== CONT TestService_NativeMTLS11682026/09/22 08:43:04 OK 20251218171726_add_pins.sql (27.41ms)11692026/09/22 08:43:04 OK 20260628120000_add_object_size_and_stats.sql (26.63ms)11702026/09/22 08:43:04 OK 20241026095416_initial_model.sql (111.78ms)11712026/09/22 08:43:04 OK 20251210153512_drop_unused_gin_index.sql (6.01ms)11722026/09/22 08:43:04 OK 20251218171726_add_pins.sql (31.73ms)11732026/09/22 08:43:04 OK 20260905000000_add_claims.sql (38.14ms)11742026/09/22 08:43:04 OK 20260920000000_drop_claims.sql (8.11ms)11752026/09/22 08:43:04 goose: successfully migrated database to version: 2026092000000011762026/09/22 08:43:04 OK 1_commit_pending_closure.sql (2.53ms)11772026/09/22 08:43:04 OK 2_object_stats_trigger.sql (520.17µs)11782026/09/22 08:43:04 goose: up to current file version: 211792026/09/22 08:43:04 OK 20260628120000_add_object_size_and_stats.sql (18.21ms)11802026-09-22 08:43:04.459 UTC [66014] ERROR: relation "goose_db_version" does not exist at character 3611812026-09-22 08:43:04.459 UTC [66014] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11822026/09/22 08:43:04 OK 20260905000000_add_claims.sql (61.48ms)11832026/09/22 08:43:04 OK 20260920000000_drop_claims.sql (24.07ms)11842026/09/22 08:43:04 goose: successfully migrated database to version: 2026092000000011852026/09/22 08:43:04 OK 1_commit_pending_closure.sql (6.85ms)11862026/09/22 08:43:04 OK 2_object_stats_trigger.sql (1.08ms)11872026/09/22 08:43:04 goose: up to current file version: 21188--- PASS: TestReadProxyNarStreaming (1.89s)1189=== CONT TestMetricsInventory11902026/09/22 08:43:04 OK 20241026095416_initial_model.sql (114.58ms)11912026/09/22 08:43:04 OK 20251210153512_drop_unused_gin_index.sql (13.16ms)11922026/09/22 08:43:04 OK 20251218171726_add_pins.sql (6.91ms)11932026-09-22 08:43:04.668 UTC [66017] ERROR: relation "goose_db_version" does not exist at character 3611942026-09-22 08:43:04.668 UTC [66017] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11952026/09/22 08:43:04 OK 20260628120000_add_object_size_and_stats.sql (25.64ms)11962026/09/22 08:43:04 OK 20260905000000_add_claims.sql (21.39ms)11972026/09/22 08:43:04 OK 20260920000000_drop_claims.sql (14.73ms)11982026/09/22 08:43:04 goose: successfully migrated database to version: 2026092000000011992026/09/22 08:43:04 OK 1_commit_pending_closure.sql (3.68ms)12002026/09/22 08:43:04 OK 2_object_stats_trigger.sql (663.08µs)12012026/09/22 08:43:04 goose: up to current file version: 21202--- PASS: TestReadProxyNarinfo (1.81s)1203=== CONT TestNARDeduplicationMetadataUploadBug12042026/09/22 08:43:04 OK 20241026095416_initial_model.sql (107.21ms)12052026/09/22 08:43:04 OK 20251210153512_drop_unused_gin_index.sql (5.41ms)12062026/09/22 08:43:04 OK 20251218171726_add_pins.sql (20.01ms)12072026/09/22 08:43:04 OK 20260628120000_add_object_size_and_stats.sql (25.43ms)12082026/09/22 08:43:04 OK 20260905000000_add_claims.sql (23.42ms)12092026/09/22 08:43:04 OK 20260920000000_drop_claims.sql (14.78ms)12102026/09/22 08:43:04 goose: successfully migrated database to version: 2026092000000012112026/09/22 08:43:04 OK 1_commit_pending_closure.sql (4.81ms)12122026/09/22 08:43:04 OK 2_object_stats_trigger.sql (753.75µs)12132026/09/22 08:43:04 goose: up to current file version: 212142026-09-22 08:43:04.912 UTC [66020] ERROR: relation "goose_db_version" does not exist at character 3612152026-09-22 08:43:04.912 UTC [66020] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12162026/09/22 08:43:04 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux12172026/09/22 08:43:04 WARN Refused reserved pin name=worker-x86_64-linux12182026/09/22 08:43:04 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux12192026/09/22 08:43:04 INFO Received create pin request method=POST path=/api/pins/my-app12202026/09/22 08:43:04 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux1221--- PASS: TestCreatePin_ReservedPins (1.90s)1222=== CONT TestGCTaskStore_CompletedAllowsNewTask1223--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)1224=== CONT TestCacheConfigHandlerMaxNarSize1225--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)1226=== CONT TestGenerateLandingPage1227--- PASS: TestGenerateLandingPage (0.00s)1228=== CONT TestService_readinessHandler12292026/09/22 08:43:05 OK 20241026095416_initial_model.sql (123.31ms)12302026/09/22 08:43:05 OK 20251210153512_drop_unused_gin_index.sql (12.31ms)12312026/09/22 08:43:05 OK 20251218171726_add_pins.sql (34ms)12322026/09/22 08:43:05 OK 20260628120000_add_object_size_and_stats.sql (23.24ms)12332026/09/22 08:43:05 OK 20260905000000_add_claims.sql (52.27ms)12342026/09/22 08:43:05 OK 20260920000000_drop_claims.sql (58.94ms)12352026/09/22 08:43:05 goose: successfully migrated database to version: 2026092000000012362026/09/22 08:43:05 OK 1_commit_pending_closure.sql (6.96ms)12372026/09/22 08:43:05 OK 2_object_stats_trigger.sql (2.1ms)12382026/09/22 08:43:05 goose: up to current file version: 21239--- PASS: TestResurrectedObjectNotDeleted (2.02s)1240=== CONT TestLeadElectsOneAndHandsOver12412026-09-22 08:43:05.390 UTC [66023] ERROR: relation "goose_db_version" does not exist at character 3612422026-09-22 08:43:05.390 UTC [66023] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12432026/09/22 08:43:05 OK 20241026095416_initial_model.sql (172.82ms)12442026/09/22 08:43:05 OK 20251210153512_drop_unused_gin_index.sql (15.81ms)12452026/09/22 08:43:05 OK 20251218171726_add_pins.sql (43.57ms)12462026/09/22 08:43:05 OK 20260628120000_add_object_size_and_stats.sql (42.89ms)12472026/09/22 08:43:05 OK 20260905000000_add_claims.sql (86.88ms)12482026/09/22 08:43:05 OK 20260920000000_drop_claims.sql (45.24ms)12492026/09/22 08:43:05 goose: successfully migrated database to version: 2026092000000012502026/09/22 08:43:05 OK 1_commit_pending_closure.sql (7.07ms)12512026/09/22 08:43:05 OK 2_object_stats_trigger.sql (1.14ms)12522026/09/22 08:43:05 goose: up to current file version: 212532026-09-22 08:43:05.867 UTC [66026] ERROR: relation "goose_db_version" does not exist at character 3612542026-09-22 08:43:05.867 UTC [66026] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12552026/09/22 08:43:05 WARN Rate limiter enabled after throttle name=s3-test rate=512562026/09/22 08:43:05 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."1257=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle1258 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=101259 throttle_test.go:215: Rate limiter: enabled=true, rate=5.001260--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (6.75s)1261=== CONT TestGCTaskStore_GetReturnsLatest1262--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)1263=== CONT TestGCTaskStore_GetEmpty1264--- PASS: TestGCTaskStore_GetEmpty (0.00s)1265=== CONT TestGCTaskStore_ConflictDifferentParams1266--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)1267=== CONT TestGCTaskStore_DeduplicateSameParams1268--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)1269=== CONT TestGCTaskStore_StartNew1270--- PASS: TestGCTaskStore_StartNew (0.00s)1271=== CONT TestGCMetrics12722026/09/22 08:43:06 OK 20241026095416_initial_model.sql (173.09ms)12732026/09/22 08:43:06 OK 20251210153512_drop_unused_gin_index.sql (13.63ms)1274--- PASS: TestObjectStatsTrigger (2.18s)1275=== CONT TestGCBugBareHashReferences12762026/09/22 08:43:06 OK 20251218171726_add_pins.sql (33.21ms)12772026/09/22 08:43:06 OK 20260628120000_add_object_size_and_stats.sql (33.58ms)12782026-09-22 08:43:06.234 UTC [66031] ERROR: relation "goose_db_version" does not exist at character 3612792026-09-22 08:43:06.234 UTC [66031] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12802026/09/22 08:43:06 OK 20260905000000_add_claims.sql (91.57ms)12812026/09/22 08:43:06 OK 20260920000000_drop_claims.sql (47.68ms)12822026/09/22 08:43:06 goose: successfully migrated database to version: 2026092000000012832026/09/22 08:43:06 OK 1_commit_pending_closure.sql (3.41ms)12842026/09/22 08:43:06 OK 2_object_stats_trigger.sql (761.88µs)12852026/09/22 08:43:06 goose: up to current file version: 212862026/09/22 08:43:06 INFO Received uploads request method=POST path=/api/pending_closures12872026/09/22 08:43:06 OK 20241026095416_initial_model.sql (163.68ms)12882026/09/22 08:43:06 OK 20251210153512_drop_unused_gin_index.sql (17.5ms)12892026/09/22 08:43:06 OK 20251218171726_add_pins.sql (39.7ms)12902026/09/22 08:43:06 INFO Received cleanup request method=DELETE path=/api/pending_closures12912026/09/22 08:43:06 OK 20260628120000_add_object_size_and_stats.sql (65.36ms)12922026/09/22 08:43:06 INFO Aborted multipart uploads count=11293=== NAME TestOrphanedObjectsGC1294 orphaned_objects_gc_test.go:290: GC Test Summary:1295 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A1296 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B1297 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)1298 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)1299 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects1300--- PASS: TestOrphanedObjectsGC (2.92s)1301=== CONT TestLeadEndsOnShutdown1302--- PASS: TestMultipartCleanup (2.48s)1303=== CONT TestClientCADerivations13042026/09/22 08:43:06 OK 20260905000000_add_claims.sql (80.77ms)13052026/09/22 08:43:06 WARN mTLS auth: subject not in bound subjects subject="CN=reader"13062026/09/22 08:43:06 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1307--- PASS: TestService_NativeMTLS (2.35s)1308=== CONT TestResolveDBConnectionString1309=== RUN TestResolveDBConnectionString/flag_wins1310=== PAUSE TestResolveDBConnectionString/flag_wins1311=== RUN TestResolveDBConnectionString/file_when_flag_empty1312=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1313=== RUN TestResolveDBConnectionString/missing_file_is_an_error1314=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1315=== RUN TestResolveDBConnectionString/PGHOST_allows_empty1316=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1317=== RUN TestResolveDBConnectionString/nothing_configured1318=== PAUSE TestResolveDBConnectionString/nothing_configured1319=== CONT TestPinProtectsFromGC13202026/09/22 08:43:06 OK 20260920000000_drop_claims.sql (55.58ms)13212026/09/22 08:43:06 goose: successfully migrated database to version: 2026092000000013222026/09/22 08:43:06 OK 1_commit_pending_closure.sql (2.87ms)13232026/09/22 08:43:06 OK 2_object_stats_trigger.sql (573.79µs)13242026/09/22 08:43:06 goose: up to current file version: 213252026-09-22 08:43:06.770 UTC [66037] ERROR: relation "goose_db_version" does not exist at character 3613262026-09-22 08:43:06.770 UTC [66037] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13272026/09/22 08:43:07 OK 20241026095416_initial_model.sql (209.19ms)13282026/09/22 08:43:07 OK 20251210153512_drop_unused_gin_index.sql (16.4ms)13292026/09/22 08:43:07 OK 20251218171726_add_pins.sql (22.74ms)1330--- PASS: TestMetricsInventory (2.55s)1331=== CONT TestClientSharedPathCommittedMidPush13322026/09/22 08:43:07 OK 20260628120000_add_object_size_and_stats.sql (52.22ms)13332026/09/22 08:43:07 OK 20260905000000_add_claims.sql (57.16ms)13342026-09-22 08:43:07.227 UTC [66042] ERROR: relation "goose_db_version" does not exist at character 3613352026-09-22 08:43:07.227 UTC [66042] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13362026/09/22 08:43:07 OK 20260920000000_drop_claims.sql (36.2ms)13372026/09/22 08:43:07 goose: successfully migrated database to version: 2026092000000013382026/09/22 08:43:07 OK 1_commit_pending_closure.sql (3.54ms)13392026/09/22 08:43:07 OK 2_object_stats_trigger.sql (802.29µs)13402026/09/22 08:43:07 goose: up to current file version: 213412026/09/22 08:43:07 OK 20241026095416_initial_model.sql (240.88ms)13422026/09/22 08:43:07 OK 20251210153512_drop_unused_gin_index.sql (15.62ms)13432026/09/22 08:43:07 OK 20251218171726_add_pins.sql (44.74ms)13442026/09/22 08:43:07 OK 20260628120000_add_object_size_and_stats.sql (40.94ms)13452026-09-22 08:43:07.649 UTC [66043] ERROR: relation "goose_db_version" does not exist at character 3613462026-09-22 08:43:07.649 UTC [66043] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13472026/09/22 08:43:07 OK 20260905000000_add_claims.sql (53.64ms)13482026/09/22 08:43:07 OK 20260920000000_drop_claims.sql (34.25ms)13492026/09/22 08:43:07 goose: successfully migrated database to version: 2026092000000013502026/09/22 08:43:07 OK 1_commit_pending_closure.sql (2.09ms)13512026/09/22 08:43:07 OK 2_object_stats_trigger.sql (342.79µs)13522026/09/22 08:43:07 goose: up to current file version: 21353=== NAME TestNARDeduplicationMetadataUploadBug1354 metadata_upload_test.go:48: First store path: /nix/var/nix/builds/nix-65797-4283757879/TestNARDeduplicationMetadataUploadBug963492914/001/store/b3a8wmimhg5h4wqz0z07xh9ch4h05sk1-file1.txt13552026/09/22 08:43:07 OK 20241026095416_initial_model.sql (237.93ms)13562026/09/22 08:43:07 OK 20251210153512_drop_unused_gin_index.sql (12.91ms)13572026/09/22 08:43:07 OK 20251218171726_add_pins.sql (29.13ms)13582026/09/22 08:43:08 OK 20260628120000_add_object_size_and_stats.sql (29.98ms)13592026/09/22 08:43:08 WARN readiness check failed error="closed pool"1360--- PASS: TestService_readinessHandler (3.08s)1361=== CONT TestClientWithDependencies13622026/09/22 08:43:08 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"13632026/09/22 08:43:08 OK 20260905000000_add_claims.sql (56.59ms)13642026/09/22 08:43:08 OK 20260920000000_drop_claims.sql (34.05ms)13652026/09/22 08:43:08 goose: successfully migrated database to version: 2026092000000013662026/09/22 08:43:08 INFO Received uploads request method=POST path=/api/pending_closures13672026/09/22 08:43:08 OK 1_commit_pending_closure.sql (26.29ms)13682026/09/22 08:43:08 OK 2_object_stats_trigger.sql (462.92µs)13692026/09/22 08:43:08 goose: up to current file version: 213702026/09/22 08:43:08 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)13712026/09/22 08:43:08 INFO Uploading b3a8wmimhg5h4wqz0z07xh9ch4h05sk1-file1.txt (160B)13722026/09/22 08:43:08 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"13732026/09/22 08:43:08 WARN Failed to register uploaded object key=b3a8wmimhg5h4wqz0z07xh9ch4h05sk1.ls error="server returned 404: 404 page not found\n"13742026/09/22 08:43:08 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign13752026/09/22 08:43:08 INFO Signed narinfos id=1 count=113762026/09/22 08:43:08 INFO Uploading 1 narinfos13772026/09/22 08:43:08 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete13782026/09/22 08:43:08 WARN Failed to register uploaded object key=b3a8wmimhg5h4wqz0z07xh9ch4h05sk1.narinfo error="server returned 404: 404 page not found\n"13792026/09/22 08:43:08 INFO Completed upload id=113802026/09/22 08:43:08 INFO Upload complete. (297ms)1381=== NAME TestNARDeduplicationMetadataUploadBug1382 metadata_upload_test.go:54: Retrieved narinfo from S3:1383 StorePath: /nix/var/nix/builds/nix-65797-4283757879/TestNARDeduplicationMetadataUploadBug963492914/001/store/b3a8wmimhg5h4wqz0z07xh9ch4h05sk1-file1.txt1384 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1385 Compression: zstd1386 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1387 NarSize: 1601388 References: 1389 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1390 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1391 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1392 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}13932026-09-22 08:43:08.332 UTC [66054] ERROR: relation "goose_db_version" does not exist at character 3613942026-09-22 08:43:08.332 UTC [66054] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13952026-09-22 08:43:08.395 UTC [66057] ERROR: relation "goose_db_version" does not exist at character 3613962026-09-22 08:43:08.395 UTC [66057] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1397 metadata_upload_test.go:64: Second store path (same content): /nix/var/nix/builds/nix-65797-4283757879/TestNARDeduplicationMetadataUploadBug963492914/001/store/x55r0dxg12ilk3fy4v49155axibyly7h-file2.txt13982026/09/22 08:43:08 INFO lead: acquired remote=192.0.2.1:123413992026/09/22 08:43:08 OK 20241026095416_initial_model.sql (93.99ms)14002026/09/22 08:43:08 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"14012026/09/22 08:43:08 OK 20251210153512_drop_unused_gin_index.sql (10.87ms)14022026/09/22 08:43:08 OK 20241026095416_initial_model.sql (64.71ms)14032026/09/22 08:43:08 OK 20251218171726_add_pins.sql (7.36ms)14042026/09/22 08:43:08 OK 20251210153512_drop_unused_gin_index.sql (2.66ms)14052026/09/22 08:43:08 OK 20251218171726_add_pins.sql (11.76ms)14062026/09/22 08:43:08 OK 20260628120000_add_object_size_and_stats.sql (20.95ms)14072026/09/22 08:43:08 INFO Received uploads request method=POST path=/api/pending_closures14082026/09/22 08:43:08 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)14092026/09/22 08:43:08 OK 20260628120000_add_object_size_and_stats.sql (31.6ms)14102026/09/22 08:43:08 OK 20260905000000_add_claims.sql (24.75ms)14112026/09/22 08:43:08 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign14122026/09/22 08:43:08 INFO Signed narinfos id=2 count=114132026/09/22 08:43:08 WARN Failed to register uploaded object key=x55r0dxg12ilk3fy4v49155axibyly7h.ls error="server returned 404: 404 page not found\n"14142026/09/22 08:43:08 INFO Uploading 1 narinfos14152026/09/22 08:43:08 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete14162026/09/22 08:43:08 WARN Failed to register uploaded object key=x55r0dxg12ilk3fy4v49155axibyly7h.narinfo error="server returned 404: 404 page not found\n"14172026/09/22 08:43:08 INFO Completed upload id=214182026/09/22 08:43:08 INFO Upload complete. (109ms)1419 metadata_upload_test.go:76: Retrieved narinfo from S3:1420 StorePath: /nix/var/nix/builds/nix-65797-4283757879/TestNARDeduplicationMetadataUploadBug963492914/001/store/x55r0dxg12ilk3fy4v49155axibyly7h-file2.txt1421 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1422 Compression: zstd1423 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1424 NarSize: 1601425 References: 1426 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1427 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1428 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1429 {"version":1,"root":{"type":"regular","size":44}}14302026/09/22 08:43:08 OK 20260920000000_drop_claims.sql (15ms)14312026/09/22 08:43:08 goose: successfully migrated database to version: 2026092000000014322026/09/22 08:43:08 OK 20260905000000_add_claims.sql (16.12ms)14332026-09-22 08:43:08.569 UTC [66065] ERROR: relation "goose_db_version" does not exist at character 3614342026-09-22 08:43:08.569 UTC [66065] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14352026/09/22 08:43:08 OK 1_commit_pending_closure.sql (1.59ms)14362026/09/22 08:43:08 OK 2_object_stats_trigger.sql (245.54µs)14372026/09/22 08:43:08 goose: up to current file version: 214382026-09-22 08:43:08.578 UTC [66066] ERROR: relation "goose_db_version" does not exist at character 3614392026-09-22 08:43:08.578 UTC [66066] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14402026-09-22 08:43:08.579 UTC [66067] ERROR: relation "goose_db_version" does not exist at character 3614412026-09-22 08:43:08.579 UTC [66067] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1442--- PASS: TestNARDeduplicationMetadataUploadBug (3.81s)1443=== CONT TestClientMultipleUploads14442026/09/22 08:43:08 INFO lead: released remote=192.0.2.1:123414452026/09/22 08:43:08 OK 20260920000000_drop_claims.sql (25.69ms)14462026/09/22 08:43:08 goose: successfully migrated database to version: 2026092000000014472026/09/22 08:43:08 OK 1_commit_pending_closure.sql (879.88µs)14482026/09/22 08:43:08 OK 2_object_stats_trigger.sql (228.17µs)14492026/09/22 08:43:08 goose: up to current file version: 214502026/09/22 08:43:08 INFO lead: acquired remote=192.0.2.1:123414512026/09/22 08:43:08 INFO lead: released remote=192.0.2.1:12341452--- PASS: TestLeadElectsOneAndHandsOver (3.32s)1453=== CONT TestClientIntegration14542026/09/22 08:43:08 OK 20241026095416_initial_model.sql (163.08ms)14552026/09/22 08:43:08 OK 20241026095416_initial_model.sql (151.21ms)14562026/09/22 08:43:08 OK 20251210153512_drop_unused_gin_index.sql (1.13ms)14572026/09/22 08:43:08 OK 20251210153512_drop_unused_gin_index.sql (11.37ms)14582026/09/22 08:43:08 OK 20241026095416_initial_model.sql (170.72ms)14592026/09/22 08:43:08 OK 20251210153512_drop_unused_gin_index.sql (7.36ms)14602026/09/22 08:43:08 OK 20251218171726_add_pins.sql (34.76ms)14612026/09/22 08:43:08 OK 20251218171726_add_pins.sql (32.99ms)14622026/09/22 08:43:08 INFO Aborted multipart uploads count=014632026/09/22 08:43:08 OK 20251218171726_add_pins.sql (24.96ms)14642026/09/22 08:43:08 WARN Force mode enabled - objects will be deleted immediately without grace period14652026/09/22 08:43:08 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=014662026/09/22 08:43:08 INFO Vacuumed table table=pending_closures14672026/09/22 08:43:08 INFO Vacuumed table table=pending_objects14682026/09/22 08:43:08 INFO Vacuumed table table=multipart_uploads14692026/09/22 08:43:08 INFO Vacuumed table table=closures14702026/09/22 08:43:08 INFO Vacuumed table table=objects1471--- PASS: TestGCMetrics (2.93s)1472=== CONT TestClientErrorHandling1473=== RUN TestClientErrorHandling/InvalidStorePath1474=== PAUSE TestClientErrorHandling/InvalidStorePath1475=== RUN TestClientErrorHandling/InvalidAuthToken1476=== PAUSE TestClientErrorHandling/InvalidAuthToken1477=== RUN TestClientErrorHandling/ServerNotAvailable1478=== PAUSE TestClientErrorHandling/ServerNotAvailable1479=== CONT TestGracefulShutdownDrainsInflight14802026/09/22 08:43:08 INFO Starting HTTP server address=127.0.0.1:5276514812026/09/22 08:43:08 INFO Shutdown signal received, draining in-flight requests timeout=10s14822026/09/22 08:43:08 OK 20260628120000_add_object_size_and_stats.sql (35.91ms)14832026/09/22 08:43:08 OK 20260628120000_add_object_size_and_stats.sql (49.31ms)14842026/09/22 08:43:08 OK 20260628120000_add_object_size_and_stats.sql (48.28ms)14852026/09/22 08:43:08 OK 20260905000000_add_claims.sql (33.33ms)14862026/09/22 08:43:08 OK 20260905000000_add_claims.sql (26.57ms)1487--- PASS: TestGracefulShutdownDrainsInflight (0.07s)1488=== CONT TestService_healthCheckHandler14892026/09/22 08:43:08 OK 20260905000000_add_claims.sql (40.6ms)14902026/09/22 08:43:08 OK 20260920000000_drop_claims.sql (42.77ms)14912026/09/22 08:43:08 goose: successfully migrated database to version: 2026092000000014922026/09/22 08:43:08 OK 20260920000000_drop_claims.sql (27.49ms)14932026/09/22 08:43:08 goose: successfully migrated database to version: 2026092000000014942026/09/22 08:43:08 OK 1_commit_pending_closure.sql (3.34ms)14952026/09/22 08:43:08 OK 1_commit_pending_closure.sql (3.29ms)14962026/09/22 08:43:08 OK 2_object_stats_trigger.sql (560.75µs)14972026/09/22 08:43:08 goose: up to current file version: 214982026/09/22 08:43:08 OK 2_object_stats_trigger.sql (579.75µs)14992026/09/22 08:43:08 goose: up to current file version: 215002026/09/22 08:43:08 OK 20260920000000_drop_claims.sql (35.15ms)15012026/09/22 08:43:08 goose: successfully migrated database to version: 2026092000000015022026/09/22 08:43:08 OK 1_commit_pending_closure.sql (2.27ms)15032026/09/22 08:43:08 OK 2_object_stats_trigger.sql (492.92µs)15042026/09/22 08:43:08 goose: up to current file version: 215052026-09-22 08:43:09.109 UTC [66076] ERROR: relation "goose_db_version" does not exist at character 3615062026-09-22 08:43:09.109 UTC [66076] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15072026/09/22 08:43:09 OK 20241026095416_initial_model.sql (183.98ms)1508--- PASS: TestGCBugBareHashReferences (3.22s)1509=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT15102026/09/22 08:43:09 OK 20251210153512_drop_unused_gin_index.sql (14.16ms)15112026/09/22 08:43:09 INFO lead: acquired remote=192.0.2.1:123415122026/09/22 08:43:09 INFO lead: released remote=192.0.2.1:12341513--- PASS: TestLeadEndsOnShutdown (2.75s)1514=== CONT TestService_RequireScope_OIDC15152026/09/22 08:43:09 OK 20251218171726_add_pins.sql (33.73ms)15162026/09/22 08:43:09 OK 20260628120000_add_object_size_and_stats.sql (39.69ms)15172026/09/22 08:43:09 OK 20260905000000_add_claims.sql (46.4ms)15182026/09/22 08:43:09 OK 20260920000000_drop_claims.sql (23.14ms)15192026/09/22 08:43:09 goose: successfully migrated database to version: 2026092000000015202026/09/22 08:43:09 OK 1_commit_pending_closure.sql (1.03ms)15212026/09/22 08:43:09 OK 2_object_stats_trigger.sql (228.54µs)15222026/09/22 08:43:09 goose: up to current file version: 215232026/09/22 08:43:09 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:52769/oidc15242026-09-22 08:43:09.655 UTC [66082] ERROR: relation "goose_db_version" does not exist at character 3615252026-09-22 08:43:09.655 UTC [66082] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1526=== NAME TestPinProtectsFromGC1527 client_integration_test.go:731: Pinned store path: /nix/var/nix/builds/nix-65797-4283757879/TestPinProtectsFromGC1515359208/001/store/j98sdvddln6pp31dnxdinqbc9l33rvmv-pinned-file.txt1528 client_integration_test.go:732: Unpinned store path: /nix/var/nix/builds/nix-65797-4283757879/TestPinProtectsFromGC1515359208/001/store/7pr008g44v9gicwp395v4a88znj3hyan-unpinned-file.txt15292026/09/22 08:43:09 OK 20241026095416_initial_model.sql (147.27ms)15302026/09/22 08:43:09 OK 20251210153512_drop_unused_gin_index.sql (10.33ms)15312026/09/22 08:43:09 OK 20251218171726_add_pins.sql (30.64ms)15322026/09/22 08:43:09 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"15332026/09/22 08:43:09 OK 20260628120000_add_object_size_and_stats.sql (34.24ms)15342026/09/22 08:43:09 OK 20260905000000_add_claims.sql (45.25ms)15352026/09/22 08:43:09 INFO Received uploads request method=POST path=/api/pending_closures15362026/09/22 08:43:10 OK 20260920000000_drop_claims.sql (46.36ms)15372026/09/22 08:43:10 goose: successfully migrated database to version: 2026092000000015382026/09/22 08:43:10 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15392026/09/22 08:43:10 INFO Uploading j98sdvddln6pp31dnxdinqbc9l33rvmv-pinned-file.txt (128B)15402026/09/22 08:43:10 OK 1_commit_pending_closure.sql (1.71ms)15412026/09/22 08:43:10 OK 2_object_stats_trigger.sql (284.92µs)15422026/09/22 08:43:10 goose: up to current file version: 215432026/09/22 08:43:10 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"15442026/09/22 08:43:10 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign15452026/09/22 08:43:10 WARN Failed to register uploaded object key=j98sdvddln6pp31dnxdinqbc9l33rvmv.ls error="server returned 404: 404 page not found\n"15462026/09/22 08:43:10 INFO Signed narinfos id=1 count=115472026/09/22 08:43:10 INFO Uploading 1 narinfos15482026/09/22 08:43:10 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete15492026/09/22 08:43:10 WARN Failed to register uploaded object key=j98sdvddln6pp31dnxdinqbc9l33rvmv.narinfo error="server returned 404: 404 page not found\n"15502026/09/22 08:43:10 INFO Completed upload id=115512026/09/22 08:43:10 INFO Upload complete. (234ms)15522026/09/22 08:43:10 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"15532026/09/22 08:43:10 INFO Received uploads request method=POST path=/api/pending_closures15542026/09/22 08:43:10 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15552026/09/22 08:43:10 INFO Uploading 7pr008g44v9gicwp395v4a88znj3hyan-unpinned-file.txt (128B)15562026/09/22 08:43:10 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"15572026-09-22 08:43:10.266 UTC [66104] ERROR: relation "goose_db_version" does not exist at character 3615582026-09-22 08:43:10.266 UTC [66104] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15592026/09/22 08:43:10 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign15602026/09/22 08:43:10 INFO Signed narinfos id=2 count=115612026/09/22 08:43:10 INFO Uploading 1 narinfos15622026/09/22 08:43:10 WARN Failed to register uploaded object key=7pr008g44v9gicwp395v4a88znj3hyan.ls error="server returned 404: 404 page not found\n"1563=== NAME TestClientCADerivations1564 client_ca_test.go:136: Built CA derivation: /nix/var/nix/builds/nix-65797-4283757879/TestClientCADerivations3860112105/001/store/gmzl3w605ldjq5sk9xj0d5agdlinnpsh-ca-test15652026/09/22 08:43:10 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete15662026/09/22 08:43:10 WARN Failed to register uploaded object key=7pr008g44v9gicwp395v4a88znj3hyan.narinfo error="server returned 404: 404 page not found\n"15672026/09/22 08:43:10 INFO Completed upload id=215682026/09/22 08:43:10 INFO Upload complete. (163ms)15692026-09-22 08:43:10.314 UTC [66106] ERROR: relation "goose_db_version" does not exist at character 3615702026-09-22 08:43:10.314 UTC [66106] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1571 client_ca_test.go:139: Found 1 dependencies (including self)15722026/09/22 08:43:10 INFO Received create pin request method=POST path=/api/pins/myapp15732026/09/22 08:43:10 INFO Created/updated pin name=myapp store_path=/nix/var/nix/builds/nix-65797-4283757879/TestPinProtectsFromGC1515359208/001/store/j98sdvddln6pp31dnxdinqbc9l33rvmv-pinned-file.txt narinfo_key=j98sdvddln6pp31dnxdinqbc9l33rvmv.narinfo15742026/09/22 08:43:10 INFO Starting cleanup of old closures method=DELETE path=/api/closures15752026/09/22 08:43:10 INFO Garbage collection started15762026/09/22 08:43:10 INFO Aborted multipart uploads count=015772026/09/22 08:43:10 WARN Force mode enabled - objects will be deleted immediately without grace period15782026/09/22 08:43:10 OK 20241026095416_initial_model.sql (58.99ms)15792026/09/22 08:43:10 OK 20251210153512_drop_unused_gin_index.sql (10.27ms)15802026-09-22 08:43:10.404 UTC [66120] ERROR: relation "goose_db_version" does not exist at character 3615812026-09-22 08:43:10.404 UTC [66120] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15822026/09/22 08:43:10 OK 20251218171726_add_pins.sql (20.35ms)15832026/09/22 08:43:10 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"15842026/09/22 08:43:10 OK 20241026095416_initial_model.sql (65.26ms)15852026/09/22 08:43:10 OK 20251210153512_drop_unused_gin_index.sql (17.81ms)15862026/09/22 08:43:10 OK 20260628120000_add_object_size_and_stats.sql (28.12ms)15872026/09/22 08:43:10 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"15882026/09/22 08:43:10 OK 20251218171726_add_pins.sql (14.72ms)15892026/09/22 08:43:10 OK 20260628120000_add_object_size_and_stats.sql (14.28ms)15902026/09/22 08:43:10 OK 20260905000000_add_claims.sql (28.45ms)15912026/09/22 08:43:10 INFO Received uploads request method=POST path=/api/pending_closures15922026/09/22 08:43:10 OK 20260920000000_drop_claims.sql (18.47ms)15932026/09/22 08:43:10 goose: successfully migrated database to version: 2026092000000015942026/09/22 08:43:10 OK 1_commit_pending_closure.sql (3.18ms)15952026/09/22 08:43:10 OK 2_object_stats_trigger.sql (556µs)15962026/09/22 08:43:10 goose: up to current file version: 215972026/09/22 08:43:10 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15982026/09/22 08:43:10 INFO Uploading gmzl3w605ldjq5sk9xj0d5agdlinnpsh-ca-test (144B)15992026/09/22 08:43:10 OK 20260905000000_add_claims.sql (40.35ms)16002026/09/22 08:43:10 INFO Received uploads request method=POST path=/api/pending_closures16012026/09/22 08:43:10 OK 20260920000000_drop_claims.sql (23.79ms)16022026/09/22 08:43:10 goose: successfully migrated database to version: 2026092000000016032026/09/22 08:43:10 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"16042026/09/22 08:43:10 WARN Failed to register uploaded object key=log/xqrm0pqxqjgbd2zgc6ynab1zrcnhhxi3-ca-test.drv error="server returned 404: 404 page not found\n"16052026/09/22 08:43:10 OK 1_commit_pending_closure.sql (1.65ms)16062026/09/22 08:43:10 OK 2_object_stats_trigger.sql (333.33µs)16072026/09/22 08:43:10 goose: up to current file version: 216082026/09/22 08:43:10 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign16092026/09/22 08:43:10 WARN Failed to register uploaded object key=gmzl3w605ldjq5sk9xj0d5agdlinnpsh.ls error="server returned 404: 404 page not found\n"16102026/09/22 08:43:10 INFO Signed narinfos id=1 count=116112026/09/22 08:43:10 INFO Uploading 1 narinfos16122026/09/22 08:43:10 OK 20241026095416_initial_model.sql (104.27ms)16132026/09/22 08:43:10 OK 20251210153512_drop_unused_gin_index.sql (869.71µs)16142026/09/22 08:43:10 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete16152026/09/22 08:43:10 WARN Failed to register uploaded object key=gmzl3w605ldjq5sk9xj0d5agdlinnpsh.narinfo error="server returned 404: 404 page not found\n"16162026/09/22 08:43:10 INFO Completed upload id=116172026/09/22 08:43:10 INFO Upload complete. (206ms)1618 client_ca_test.go:180: Narinfo contains CA field: StorePath: /nix/var/nix/builds/nix-65797-4283757879/TestClientCADerivations3860112105/001/store/gmzl3w605ldjq5sk9xj0d5agdlinnpsh-ca-test1619 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1620 Compression: zstd1621 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1622 NarSize: 1441623 References: 1624 Deriver: /nix/var/nix/builds/nix-65797-4283757879/TestClientCADerivations3860112105/001/store/xqrm0pqxqjgbd2zgc6ynab1zrcnhhxi3-ca-test.drv1625 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1626 client_ca_test.go:185: Checking for realisation files in S3...1627 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1628 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache16292026/09/22 08:43:10 OK 20251218171726_add_pins.sql (24.9ms)16302026/09/22 08:43:10 OK 20260628120000_add_object_size_and_stats.sql (29.39ms)16312026/09/22 08:43:10 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"16322026/09/22 08:43:10 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=3 objects-deleted-after-grace-period=2802 objects-failed-to-delete=016332026/09/22 08:43:10 OK 20260905000000_add_claims.sql (42.81ms)16342026/09/22 08:43:10 INFO Vacuumed table table=pending_closures16352026/09/22 08:43:10 OK 20260920000000_drop_claims.sql (16.81ms)16362026/09/22 08:43:10 goose: successfully migrated database to version: 2026092000000016372026/09/22 08:43:10 INFO Vacuumed table table=pending_objects1638 client_ca_test.go:258: nix copy output: error: binary cache 's3://bucket41?endpoint=http://localhost:52666®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/nix/var/nix/builds/nix-65797-4283757879/TestClientCADerivations3860112105/001/store'1639 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 116402026/09/22 08:43:10 INFO Vacuumed table table=multipart_uploads16412026/09/22 08:43:10 OK 1_commit_pending_closure.sql (1.4ms)16422026/09/22 08:43:10 OK 2_object_stats_trigger.sql (240.17µs)16432026/09/22 08:43:10 goose: up to current file version: 216442026/09/22 08:43:10 INFO Received uploads request method=POST path=/api/pending_closures16452026/09/22 08:43:10 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)16462026/09/22 08:43:10 INFO Uploading ljmhaad0qq0h04y1dzdnrjlw4c4mn060-shared-dep (136B)16472026/09/22 08:43:10 INFO Vacuumed table table=closures16482026/09/22 08:43:10 INFO Vacuumed table table=objects16492026/09/22 08:43:10 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"1650=== NAME TestClientWithDependencies1651 client_integration_test.go:613: Built derivation: /nix/var/nix/builds/nix-65797-4283757879/TestClientWithDependencies2640920416/001/store/4izpcpq59lwqhvy4rw6is3vyycllz77p-test-script16522026/09/22 08:43:10 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign16532026/09/22 08:43:10 WARN Failed to register uploaded object key=ljmhaad0qq0h04y1dzdnrjlw4c4mn060.ls error="server returned 404: 404 page not found\n"16542026/09/22 08:43:10 INFO Signed narinfos id=2 count=116552026/09/22 08:43:10 INFO Uploading 1 narinfos16562026/09/22 08:43:10 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete16572026-09-22 08:43:10.710 UTC [66141] ERROR: relation "goose_db_version" does not exist at character 3616582026-09-22 08:43:10.710 UTC [66141] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16592026/09/22 08:43:10 WARN Failed to register uploaded object key=ljmhaad0qq0h04y1dzdnrjlw4c4mn060.narinfo error="server returned 404: 404 page not found\n"1660--- PASS: TestClientCADerivations (4.10s)1661=== CONT TestCacheStatsHandler16622026/09/22 08:43:10 INFO Completed upload id=216632026/09/22 08:43:10 INFO Upload complete. (160ms)16642026/09/22 08:43:10 INFO Received uploads request method=POST path=/api/pending_closures16652026/09/22 08:43:10 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)16662026/09/22 08:43:10 INFO Uploading ljmhaad0qq0h04y1dzdnrjlw4c4mn060-shared-dep (136B)16672026/09/22 08:43:10 INFO Uploading sfv4409lnpl3mjjqs73zdlijazy8xf0s-top (256B)16682026/09/22 08:43:10 WARN Failed to register uploaded object key=nar/0qwkql0ir24n633gxflzlzh2m8b6ys60jmvpm2jp2hkqy24vxa4s.nar.zst error="server returned 404: 404 page not found\n"1669=== NAME TestClientWithDependencies1670 client_integration_test.go:615: Found 1 dependencies (including self)16712026/09/22 08:43:10 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"16722026/09/22 08:43:10 WARN Failed to register uploaded object key=sfv4409lnpl3mjjqs73zdlijazy8xf0s.ls error="server returned 404: 404 page not found\n"16732026/09/22 08:43:10 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign16742026/09/22 08:43:10 INFO Signed narinfos id=1 count=116752026/09/22 08:43:10 WARN Failed to register uploaded object key=ljmhaad0qq0h04y1dzdnrjlw4c4mn060.ls error="server returned 404: 404 page not found\n"16762026/09/22 08:43:10 INFO Received sign narinfos request method=POST path=/api/pending_closures/3/sign16772026/09/22 08:43:10 INFO Signed narinfos id=3 count=116782026/09/22 08:43:10 INFO Uploading 2 narinfos16792026/09/22 08:43:10 WARN Failed to register uploaded object key=sfv4409lnpl3mjjqs73zdlijazy8xf0s.narinfo error="server returned 404: 404 page not found\n"16802026/09/22 08:43:10 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete16812026/09/22 08:43:10 WARN Failed to register uploaded object key=ljmhaad0qq0h04y1dzdnrjlw4c4mn060.narinfo error="server returned 404: 404 page not found\n"16822026/09/22 08:43:10 INFO Completed upload id=116832026/09/22 08:43:10 INFO Received complete upload request method=POST path=/api/pending_closures/3/complete16842026/09/22 08:43:10 INFO Completed upload id=316852026/09/22 08:43:10 INFO Upload complete. (415ms)1686=== NAME TestClientSharedPathCommittedMidPush1687 client_integration_test.go:680: Retrieved narinfo from S3:1688 StorePath: /nix/var/nix/builds/nix-65797-4283757879/TestClientSharedPathCommittedMidPush3103496555/001/store/ljmhaad0qq0h04y1dzdnrjlw4c4mn060-shared-dep1689 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1690 Compression: zstd1691 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821692 NarSize: 1361693 References: 1694 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1695 client_integration_test.go:680: Retrieved narinfo from S3:1696 StorePath: /nix/var/nix/builds/nix-65797-4283757879/TestClientSharedPathCommittedMidPush3103496555/001/store/sfv4409lnpl3mjjqs73zdlijazy8xf0s-top1697 URL: nar/0qwkql0ir24n633gxflzlzh2m8b6ys60jmvpm2jp2hkqy24vxa4s.nar.zst1698 Compression: zstd1699 NarHash: sha256:0qwkql0ir24n633gxflzlzh2m8b6ys60jmvpm2jp2hkqy24vxa4s1700 NarSize: 2561701 References: /nix/var/nix/builds/nix-65797-4283757879/TestClientSharedPathCommittedMidPush3103496555/001/store/ljmhaad0qq0h04y1dzdnrjlw4c4mn060-shared-dep1702 CA: text:sha256:094xn7a83yqz87zxmfqa1lj2afsi3p4liyyjk2dbzpr8y55m6hvk17032026-09-22 08:43:10.802 UTC [66150] ERROR: relation "goose_db_version" does not exist at character 3617042026-09-22 08:43:10.802 UTC [66150] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1705=== NAME TestOrphanedObjectsGCStressTest1706 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains17072026/09/22 08:43:10 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"17082026/09/22 08:43:10 INFO Received uploads request method=POST path=/api/pending_closures17092026/09/22 08:43:10 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)17102026/09/22 08:43:10 INFO Uploading 4izpcpq59lwqhvy4rw6is3vyycllz77p-test-script (136B)17112026/09/22 08:43:10 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"1712--- PASS: TestClientSharedPathCommittedMidPush (3.72s)1713=== CONT TestCacheConfigHandler1714=== RUN TestCacheConfigHandler/full_config,_no_issuer1715=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1716=== RUN TestCacheConfigHandler/no_cache_url_configured1717=== PAUSE TestCacheConfigHandler/no_cache_url_configured1718=== RUN TestCacheConfigHandler/no_signing_keys1719=== PAUSE TestCacheConfigHandler/no_signing_keys1720=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1721=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1722=== CONT TestService_ReadScope_PublicByDefault17232026/09/22 08:43:10 WARN Failed to register uploaded object key=4izpcpq59lwqhvy4rw6is3vyycllz77p.ls error="server returned 404: 404 page not found\n"17242026/09/22 08:43:10 WARN Failed to register uploaded object key=log/m16fmc1zijr7q9h7ns1gw981cfg5v3v2-test-script.drv error="server returned 404: 404 page not found\n"17252026/09/22 08:43:10 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign17262026/09/22 08:43:10 OK 20241026095416_initial_model.sql (94.27ms)17272026/09/22 08:43:10 INFO Signed narinfos id=1 count=117282026/09/22 08:43:10 INFO Uploading 1 narinfos1729=== NAME TestOrphanedObjectsGCStressTest1730 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion17312026/09/22 08:43:10 OK 20251210153512_drop_unused_gin_index.sql (17.15ms)17322026/09/22 08:43:10 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete17332026/09/22 08:43:10 WARN Failed to register uploaded object key=4izpcpq59lwqhvy4rw6is3vyycllz77p.narinfo error="server returned 404: 404 page not found\n"17342026/09/22 08:43:10 OK 20251218171726_add_pins.sql (11.01ms)17352026/09/22 08:43:10 INFO Completed upload id=117362026/09/22 08:43:10 INFO Upload complete. (118ms)1737=== NAME TestClientIntegration1738 client_integration_test.go:286: Created store path: /nix/var/nix/builds/nix-65797-4283757879/TestClientIntegration3958797817/002/store/178r7rr2gysnqcn7j09r11q69f3ayyl7-test-file.txt1739=== NAME TestClientWithDependencies1740 client_integration_test.go:617: Skipping nix copy test - isolated store (/nix/var/nix/builds/nix-65797-4283757879/TestClientWithDependencies2640920416/001/store) requires matching store prefix17412026/09/22 08:43:10 OK 20260628120000_add_object_size_and_stats.sql (17.76ms)1742--- PASS: TestClientWithDependencies (2.89s)1743=== CONT TestGCTaskStore_Fail1744--- PASS: TestGCTaskStore_Fail (0.00s)1745=== CONT TestService_ReadAuthMiddleware17462026/09/22 08:43:10 OK 20260905000000_add_claims.sql (35.39ms)17472026/09/22 08:43:10 OK 20260920000000_drop_claims.sql (11.64ms)17482026/09/22 08:43:10 goose: successfully migrated database to version: 2026092000000017492026/09/22 08:43:10 OK 20241026095416_initial_model.sql (88.12ms)17502026/09/22 08:43:10 OK 1_commit_pending_closure.sql (1.53ms)17512026/09/22 08:43:10 OK 2_object_stats_trigger.sql (268.42µs)17522026/09/22 08:43:10 goose: up to current file version: 217532026/09/22 08:43:10 OK 20251210153512_drop_unused_gin_index.sql (6.97ms)17542026/09/22 08:43:10 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"17552026/09/22 08:43:10 OK 20251218171726_add_pins.sql (16.51ms)17562026/09/22 08:43:10 OK 20260628120000_add_object_size_and_stats.sql (22.76ms)17572026/09/22 08:43:11 INFO Received uploads request method=POST path=/api/pending_closures17582026/09/22 08:43:11 OK 20260905000000_add_claims.sql (37.54ms)17592026/09/22 08:43:11 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)17602026/09/22 08:43:11 INFO Uploading 178r7rr2gysnqcn7j09r11q69f3ayyl7-test-file.txt (152B)17612026/09/22 08:43:11 OK 20260920000000_drop_claims.sql (15.27ms)17622026/09/22 08:43:11 goose: successfully migrated database to version: 2026092000000017632026/09/22 08:43:11 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"17642026/09/22 08:43:11 OK 1_commit_pending_closure.sql (1.31ms)17652026/09/22 08:43:11 OK 2_object_stats_trigger.sql (279.04µs)17662026/09/22 08:43:11 goose: up to current file version: 21767=== NAME TestClientMultipleUploads1768 client_integration_test.go:358: Created store path 0: /nix/var/nix/builds/nix-65797-4283757879/TestClientMultipleUploads2431747469/001/store/5525mpas6z94bgdp8l9m0pgv59nppw8l-test-file-0.txt17692026/09/22 08:43:11 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign17702026/09/22 08:43:11 INFO Signed narinfos id=1 count=117712026/09/22 08:43:11 WARN Failed to register uploaded object key=178r7rr2gysnqcn7j09r11q69f3ayyl7.ls error="server returned 404: 404 page not found\n"17722026/09/22 08:43:11 INFO Uploading 1 narinfos17732026/09/22 08:43:11 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete17742026/09/22 08:43:11 WARN Failed to register uploaded object key=178r7rr2gysnqcn7j09r11q69f3ayyl7.narinfo error="server returned 404: 404 page not found\n"17752026/09/22 08:43:11 INFO Completed upload id=117762026/09/22 08:43:11 INFO Upload complete. (162ms)17772026/09/22 08:43:11 INFO All 1 paths already cached1778=== NAME TestClientIntegration1779 client_integration_test.go:312: Retrieved narinfo from S3:1780 StorePath: /nix/var/nix/builds/nix-65797-4283757879/TestClientIntegration3958797817/002/store/178r7rr2gysnqcn7j09r11q69f3ayyl7-test-file.txt1781 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1782 Compression: zstd1783 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11784 NarSize: 1521785 References: 1786 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11787 client_integration_test.go:313: Retrieved .ls file from S3 (compressed size: 77 bytes)1788 client_integration_test.go:313: Decompressed .ls content (64 bytes):1789 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1790 client_integration_test.go:316: Testing garbage collection...1791--- PASS: TestService_healthCheckHandler (2.21s)1792=== CONT TestService_AuthMiddleware_OIDC1793=== NAME TestClientMultipleUploads1794 client_integration_test.go:358: Created store path 1: /nix/var/nix/builds/nix-65797-4283757879/TestClientMultipleUploads2431747469/001/store/398bdmx3ls8g8xmljlr00phf05b7n1fx-test-file-1.txt17952026/09/22 08:43:11 INFO Starting cleanup of old closures method=DELETE path=/api/closures17962026/09/22 08:43:11 INFO Garbage collection started17972026/09/22 08:43:11 INFO Aborted multipart uploads count=017982026/09/22 08:43:11 WARN Force mode enabled - objects will be deleted immediately without grace period17992026/09/22 08:43:11 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:52813/oidc1800 client_integration_test.go:358: Created store path 2: /nix/var/nix/builds/nix-65797-4283757879/TestClientMultipleUploads2431747469/001/store/iv8pzwkfjwmr1l90hhavhs3ayikif0ai-test-file-2.txt18012026/09/22 08:43:11 INFO Received uploads request method=POST path=/api/pending_closures18022026/09/22 08:43:11 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"1803--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (1.95s)1804=== CONT TestService_AuthMiddleware_MTLSBoundSubjects18052026/09/22 08:43:11 INFO Received uploads request method=POST path=/api/pending_closures18062026/09/22 08:43:11 INFO Received uploads request method=POST path=/api/pending_closures18072026/09/22 08:43:11 INFO Received uploads request method=POST path=/api/pending_closures18082026/09/22 08:43:11 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)18092026/09/22 08:43:11 INFO Uploading 398bdmx3ls8g8xmljlr00phf05b7n1fx-test-file-1.txt (160B)18102026/09/22 08:43:11 INFO Uploading iv8pzwkfjwmr1l90hhavhs3ayikif0ai-test-file-2.txt (160B)18112026/09/22 08:43:11 INFO Uploading 5525mpas6z94bgdp8l9m0pgv59nppw8l-test-file-0.txt (160B)18122026/09/22 08:43:11 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"18132026/09/22 08:43:11 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"18142026/09/22 08:43:11 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"18152026/09/22 08:43:11 WARN Failed to register uploaded object key=5525mpas6z94bgdp8l9m0pgv59nppw8l.ls error="server returned 404: 404 page not found\n"18162026/09/22 08:43:11 WARN Failed to register uploaded object key=398bdmx3ls8g8xmljlr00phf05b7n1fx.ls error="server returned 404: 404 page not found\n"18172026/09/22 08:43:11 INFO Received sign narinfos request method=POST path=/api/pending_closures/3/sign18182026/09/22 08:43:11 WARN Failed to register uploaded object key=iv8pzwkfjwmr1l90hhavhs3ayikif0ai.ls error="server returned 404: 404 page not found\n"18192026/09/22 08:43:11 INFO Signed narinfos id=3 count=118202026/09/22 08:43:11 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign18212026/09/22 08:43:11 INFO Signed narinfos id=1 count=118222026/09/22 08:43:11 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign18232026/09/22 08:43:11 INFO Signed narinfos id=2 count=118242026/09/22 08:43:11 INFO Uploading 3 narinfos18252026/09/22 08:43:11 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=018262026/09/22 08:43:11 WARN Failed to register uploaded object key=iv8pzwkfjwmr1l90hhavhs3ayikif0ai.narinfo error="server returned 404: 404 page not found\n"18272026/09/22 08:43:11 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete18282026/09/22 08:43:11 WARN Failed to register uploaded object key=398bdmx3ls8g8xmljlr00phf05b7n1fx.narinfo error="server returned 404: 404 page not found\n"18292026/09/22 08:43:11 INFO Vacuumed table table=pending_closures18302026/09/22 08:43:11 WARN Failed to register uploaded object key=5525mpas6z94bgdp8l9m0pgv59nppw8l.narinfo error="server returned 404: 404 page not found\n"18312026/09/22 08:43:11 INFO Vacuumed table table=pending_objects18322026/09/22 08:43:11 INFO Vacuumed table table=multipart_uploads18332026/09/22 08:43:11 INFO Completed upload id=118342026/09/22 08:43:11 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete18352026/09/22 08:43:11 INFO Completed upload id=218362026/09/22 08:43:11 INFO Received complete upload request method=POST path=/api/pending_closures/3/complete18372026/09/22 08:43:11 INFO Completed upload id=318382026/09/22 08:43:11 INFO Upload complete. (199ms)1839=== NAME TestClientMultipleUploads1840 client_integration_test.go:369: Uploaded 3 paths in 236.403083ms18412026/09/22 08:43:11 INFO Vacuumed table table=closures18422026/09/22 08:43:11 INFO Vacuumed table table=objects1843--- PASS: TestClientMultipleUploads (2.88s)1844=== CONT TestService_AuthMiddleware_MTLSProxyHeader1845=== RUN TestService_RequireScope_OIDC/builder_may_write1846=== PAUSE TestService_RequireScope_OIDC/builder_may_write1847=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1848=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1849=== RUN TestService_RequireScope_OIDC/ops_may_admin1850=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1851=== RUN TestService_RequireScope_OIDC/ops_may_not_write1852=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1853=== RUN TestService_RequireScope_OIDC/reader_may_not_write1854=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1855=== RUN TestService_RequireScope_OIDC/static_token_may_admin1856=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1857=== RUN TestService_RequireScope_OIDC/static_token_may_write1858=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1859=== RUN TestService_RequireScope_OIDC/reader_may_read1860=== PAUSE TestService_RequireScope_OIDC/reader_may_read1861=== RUN TestService_RequireScope_OIDC/writer_implies_read1862=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1863=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1864=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1865=== CONT TestCompleteMultipartUnregistered18662026-09-22 08:43:11.536 UTC [66189] ERROR: relation "goose_db_version" does not exist at character 3618672026-09-22 08:43:11.536 UTC [66189] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18682026-09-22 08:43:11.552 UTC [66190] ERROR: relation "goose_db_version" does not exist at character 3618692026-09-22 08:43:11.552 UTC [66190] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18702026/09/22 08:43:11 OK 20241026095416_initial_model.sql (38.11ms)18712026/09/22 08:43:11 OK 20251210153512_drop_unused_gin_index.sql (9.44ms)18722026/09/22 08:43:11 OK 20251218171726_add_pins.sql (9.3ms)18732026/09/22 08:43:11 OK 20260628120000_add_object_size_and_stats.sql (6.21ms)18742026/09/22 08:43:11 OK 20241026095416_initial_model.sql (19.01ms)18752026/09/22 08:43:11 OK 20260905000000_add_claims.sql (3.4ms)18762026/09/22 08:43:11 OK 20251210153512_drop_unused_gin_index.sql (1.06ms)18772026/09/22 08:43:11 OK 20260920000000_drop_claims.sql (2.18ms)18782026/09/22 08:43:11 goose: successfully migrated database to version: 2026092000000018792026/09/22 08:43:11 OK 20251218171726_add_pins.sql (3.78ms)18802026/09/22 08:43:11 OK 1_commit_pending_closure.sql (2.26ms)18812026/09/22 08:43:11 OK 2_object_stats_trigger.sql (258.92µs)18822026/09/22 08:43:11 goose: up to current file version: 218832026/09/22 08:43:11 OK 20260628120000_add_object_size_and_stats.sql (25.89ms)18842026/09/22 08:43:11 OK 20260905000000_add_claims.sql (21.04ms)18852026/09/22 08:43:11 OK 20260920000000_drop_claims.sql (9.59ms)18862026/09/22 08:43:11 goose: successfully migrated database to version: 2026092000000018872026/09/22 08:43:11 OK 1_commit_pending_closure.sql (905.96µs)18882026/09/22 08:43:11 OK 2_object_stats_trigger.sql (217.83µs)18892026/09/22 08:43:11 goose: up to current file version: 21890=== NAME TestOrphanedObjectsGCStressTest1891 orphaned_objects_gc_test.go:509: Stress test completed successfully:1892 orphaned_objects_gc_test.go:510: - Active objects preserved: 201893 orphaned_objects_gc_test.go:511: - Objects deleted: 2101894 orphaned_objects_gc_test.go:512: - Total GC'd: 2101895--- PASS: TestOrphanedObjectsGCStressTest (8.21s)1896=== CONT TestGCTaskStore_PhaseUpdates1897--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)1898=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key18992026/09/22 08:43:11 INFO Received request for more parts method=POST path=/1900=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info19012026/09/22 08:43:11 INFO Received uploads request method=POST path=/1902=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal19032026/09/22 08:43:11 INFO Received uploads request method=POST path=/1904=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key19052026/09/22 08:43:11 INFO Received complete multipart upload request method=POST path=/1906--- PASS: TestUploadHandlersRejectInvalidKeys (0.01s)1907 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1908 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1909 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1910 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1911=== CONT TestProxyWriteTimeout/narinfo1912=== CONT TestProxyWriteTimeout/10_GiB_nar1913=== CONT TestProxyWriteTimeout/1_GiB_nar1914=== CONT TestProxyWriteTimeout/unknown_size1915--- PASS: TestProxyWriteTimeout (0.03s)1916 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1917 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1918 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1919 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1920=== CONT TestIsValidUploadKey/nix-cache-info1921=== CONT TestIsValidUploadKey/narinfo1922=== CONT TestIsValidUploadKey/realisation_plus_in_output1923=== CONT TestIsValidUploadKey/realisation1924=== CONT TestIsValidUploadKey/build_log_equals1925=== CONT TestIsValidUploadKey/build_log_question_mark1926=== CONT TestIsValidUploadKey/build_log_plus_in_name1927=== CONT TestIsValidUploadKey/build_log_home-manager_file1928=== CONT TestIsValidUploadKey/build_log1929=== CONT TestIsValidUploadKey/listing1930=== CONT TestIsValidUploadKey/nar_plain1931=== CONT TestIsValidUploadKey/nar_xz1932=== CONT TestIsValidUploadKey/nar_zst1933=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1934=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1935=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1936=== CONT TestIsValidUploadKey/index.html1937=== CONT TestIsValidUploadKey/empty_key1938=== CONT TestIsValidUploadKey/unknown_type1939=== CONT TestIsValidUploadKey/absolute1940=== CONT TestIsValidUploadKey/traversal_nar1941=== CONT TestIsValidUploadKey/traversal1942--- PASS: TestIsValidUploadKey (0.03s)1943 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1944 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1945 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1946 --- PASS: TestIsValidUploadKey/realisation (0.00s)1947 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1948 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1949 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1950 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1951 --- PASS: TestIsValidUploadKey/build_log (0.00s)1952 --- PASS: TestIsValidUploadKey/listing (0.00s)1953 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1954 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1955 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1956 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1957 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1958 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1959 --- PASS: TestIsValidUploadKey/index.html (0.00s)1960 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1961 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1962 --- PASS: TestIsValidUploadKey/absolute (0.00s)1963 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1964 --- PASS: TestIsValidUploadKey/traversal (0.00s)1965=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure19662026/09/22 08:43:11 INFO Received uploads request method=POST path=/1967--- PASS: TestCacheStatsHandler (1.12s)1968=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts19692026/09/22 08:43:11 INFO Received request for more parts method=POST path=/1970=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart19712026/09/22 08:43:11 INFO Received complete multipart upload request method=POST path=/19722026-09-22 08:43:11.864 UTC [66191] ERROR: relation "goose_db_version" does not exist at character 3619732026-09-22 08:43:11.864 UTC [66191] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1974=== CONT TestIsValidCachePath/narinfo1975=== CONT TestIsValidCachePath/random_path1976=== CONT TestIsValidCachePath/invalid_char_u1977=== CONT TestIsValidCachePath/invalid_char_e1978=== CONT TestIsValidCachePath/traversal_in_middle1979=== CONT TestIsValidCachePath/traversal_parent1980=== CONT TestIsValidCachePath/index.html1981=== CONT TestIsValidCachePath/nix-cache-info1982=== CONT TestIsValidCachePath/realisation1983=== CONT TestIsValidCachePath/log1984=== CONT TestIsValidCachePath/ls1985=== CONT TestIsValidCachePath/empty1986=== CONT TestIsValidCachePath/nar_uncompressed1987=== CONT TestIsValidCachePath/nar_bz21988=== CONT TestIsValidCachePath/nar_xz1989=== CONT TestIsValidCachePath/nar_zst1990=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1991=== CONT TestIsValidCachePath/wrong_extension1992=== CONT TestIsValidCachePath/short_hash1993=== CONT TestIsValidCachePath/leading_slash1994--- PASS: TestIsValidCachePath (0.00s)1995 --- PASS: TestIsValidCachePath/narinfo (0.00s)1996 --- PASS: TestIsValidCachePath/random_path (0.00s)1997 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1998 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1999 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)2000 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)2001 --- PASS: TestIsValidCachePath/index.html (0.00s)2002 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)2003 --- PASS: TestIsValidCachePath/realisation (0.00s)2004 --- PASS: TestIsValidCachePath/log (0.00s)2005 --- PASS: TestIsValidCachePath/ls (0.00s)2006 --- PASS: TestIsValidCachePath/empty (0.00s)2007 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)2008 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)2009 --- PASS: TestIsValidCachePath/nar_xz (0.00s)2010 --- PASS: TestIsValidCachePath/nar_zst (0.00s)2011 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)2012 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)2013 --- PASS: TestIsValidCachePath/short_hash (0.00s)2014 --- PASS: TestIsValidCachePath/leading_slash (0.00s)2015=== CONT TestParseSingleRange/none2016=== CONT TestParseSingleRange/open-ended2017=== CONT TestParseSingleRange/start_far_past_EOF2018=== CONT TestParseSingleRange/start_past_EOF2019=== CONT TestParseSingleRange/single_byte2020=== CONT TestParseSingleRange/suffix_exceeds_size2021=== CONT TestParseSingleRange/suffix2022=== CONT TestParseSingleRange/end_clamped_to_size2023=== CONT TestParseSingleRange/malformed_both_empty2024=== CONT TestParseSingleRange/closed2025=== CONT TestParseSingleRange/malformed_end_before_start2026=== CONT TestParseSingleRange/multi-range_ignored2027=== CONT TestParseSingleRange/malformed_no_dash2028=== CONT TestParseSingleRange/unknown_unit2029--- PASS: TestParseSingleRange (0.00s)2030 --- PASS: TestParseSingleRange/none (0.00s)2031 --- PASS: TestParseSingleRange/open-ended (0.00s)2032 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)2033 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)2034 --- PASS: TestParseSingleRange/single_byte (0.00s)2035 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)2036 --- PASS: TestParseSingleRange/suffix (0.00s)2037 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)2038 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)2039 --- PASS: TestParseSingleRange/closed (0.00s)2040 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)2041 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)2042 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)2043 --- PASS: TestParseSingleRange/unknown_unit (0.00s)2044=== CONT TestServerTLSConfig/no_client_CA2045=== CONT TestServerTLSConfig/missing_CA_file2046=== CONT TestServerTLSConfig/not_a_PEM_file2047--- PASS: TestServerTLSConfig (0.00s)2048 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)2049 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)2050 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.01s)2051=== CONT TestResolveDBConnectionString/flag_wins2052=== CONT TestResolveDBConnectionString/PGHOST_allows_empty2053=== CONT TestResolveDBConnectionString/nothing_configured2054=== CONT TestResolveDBConnectionString/missing_file_is_an_error2055=== CONT TestResolveDBConnectionString/file_when_flag_empty2056=== CONT TestClientErrorHandling/InvalidStorePath2057--- PASS: TestResolveDBConnectionString (0.02s)2058 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)2059 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)2060 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)2061 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)2062 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)20632026/09/22 08:43:11 OK 20241026095416_initial_model.sql (56.48ms)2064=== CONT TestClientErrorHandling/ServerNotAvailable2065--- PASS: TestUploadHandlersRejectOversizedBody (0.06s)2066 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.02s)2067 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.02s)2068 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.27s)20692026/09/22 08:43:11 OK 20251210153512_drop_unused_gin_index.sql (7.51ms)2070--- PASS: TestService_ReadScope_PublicByDefault (1.12s)2071=== CONT TestClientErrorHandling/InvalidAuthToken20722026/09/22 08:43:11 OK 20251218171726_add_pins.sql (12.45ms)20732026/09/22 08:43:11 OK 20260628120000_add_object_size_and_stats.sql (19.76ms)20742026/09/22 08:43:11 OK 20260905000000_add_claims.sql (8.58ms)20752026/09/22 08:43:11 OK 20260920000000_drop_claims.sql (1.12ms)20762026/09/22 08:43:11 goose: successfully migrated database to version: 2026092000000020772026-09-22 08:43:11.998 UTC [66198] ERROR: relation "goose_db_version" does not exist at character 3620782026-09-22 08:43:11.998 UTC [66198] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC20792026/09/22 08:43:12 OK 1_commit_pending_closure.sql (4.83ms)20802026/09/22 08:43:12 OK 2_object_stats_trigger.sql (326.71µs)20812026/09/22 08:43:12 goose: up to current file version: 220822026-09-22 08:43:12.015 UTC [66199] ERROR: relation "goose_db_version" does not exist at character 3620832026-09-22 08:43:12.015 UTC [66199] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC20842026/09/22 08:43:12 OK 20241026095416_initial_model.sql (25.97ms)20852026/09/22 08:43:12 OK 20251210153512_drop_unused_gin_index.sql (6.93ms)20862026/09/22 08:43:12 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/present20872026/09/22 08:43:12 OK 20241026095416_initial_model.sql (39.82ms)20882026/09/22 08:43:12 OK 20251218171726_add_pins.sql (12.95ms)20892026/09/22 08:43:12 OK 20251210153512_drop_unused_gin_index.sql (6.87ms)20902026/09/22 08:43:12 OK 20251218171726_add_pins.sql (7.22ms)20912026/09/22 08:43:12 OK 20260628120000_add_object_size_and_stats.sql (12.34ms)20922026/09/22 08:43:12 OK 20260628120000_add_object_size_and_stats.sql (18.79ms)20932026/09/22 08:43:12 OK 20260905000000_add_claims.sql (25.12ms)20942026/09/22 08:43:12 OK 20260920000000_drop_claims.sql (6.37ms)20952026/09/22 08:43:12 goose: successfully migrated database to version: 2026092000000020962026/09/22 08:43:12 OK 20260905000000_add_claims.sql (17.92ms)20972026/09/22 08:43:12 OK 1_commit_pending_closure.sql (933.08µs)20982026/09/22 08:43:12 OK 2_object_stats_trigger.sql (218.04µs)20992026/09/22 08:43:12 goose: up to current file version: 221002026/09/22 08:43:12 OK 20260920000000_drop_claims.sql (14ms)21012026/09/22 08:43:12 goose: successfully migrated database to version: 2026092000000021022026/09/22 08:43:12 OK 1_commit_pending_closure.sql (1.03ms)21032026/09/22 08:43:12 OK 2_object_stats_trigger.sql (253.92µs)21042026/09/22 08:43:12 goose: up to current file version: 22105--- PASS: TestService_ReadAuthMiddleware (1.25s)2106=== CONT TestCacheConfigHandler/full_config,_no_issuer2107=== CONT TestCacheConfigHandler/no_signing_keys2108=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator2109=== CONT TestCacheConfigHandler/no_cache_url_configured2110--- PASS: TestCacheConfigHandler (0.00s)2111 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)2112 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)2113 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)2114 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)2115=== CONT TestService_RequireScope_OIDC/builder_may_write2116=== CONT TestService_RequireScope_OIDC/static_token_may_admin2117=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read2118=== CONT TestService_RequireScope_OIDC/writer_implies_read2119=== CONT TestService_RequireScope_OIDC/reader_may_read2120=== CONT TestService_RequireScope_OIDC/static_token_may_write2121=== CONT TestService_RequireScope_OIDC/ops_may_not_write2122=== CONT TestService_RequireScope_OIDC/reader_may_not_write2123=== CONT TestService_RequireScope_OIDC/ops_may_admin2124=== CONT TestService_RequireScope_OIDC/builder_may_not_admin2125--- PASS: TestService_RequireScope_OIDC (2.12s)2126 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)2127 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)2128 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)2129 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)2130 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)2131 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)2132 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)2133 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)2134 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)2135 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)21362026/09/22 08:43:12 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=214.14025ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/objects/present21372026-09-22 08:43:12.247 UTC [66202] ERROR: relation "goose_db_version" does not exist at character 3621382026-09-22 08:43:12.247 UTC [66202] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC21392026-09-22 08:43:12.274 UTC [66203] ERROR: relation "goose_db_version" does not exist at character 3621402026-09-22 08:43:12.274 UTC [66203] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC21412026/09/22 08:43:12 OK 20241026095416_initial_model.sql (64.73ms)21422026/09/22 08:43:12 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"21432026/09/22 08:43:12 WARN mTLS auth: bound subjects configured but subject DN unavailable21442026/09/22 08:43:12 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"2145--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (1.03s)21462026/09/22 08:43:12 OK 20251210153512_drop_unused_gin_index.sql (1.64ms)21472026/09/22 08:43:12 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2802 objects_failed=02148=== NAME TestPinProtectsFromGC2149 client_integration_test.go:794: Pin successfully protected closure from garbage collection21502026/09/22 08:43:12 OK 20251218171726_add_pins.sql (44.07ms)2151--- PASS: TestPinProtectsFromGC (5.67s)21522026/09/22 08:43:12 OK 20260628120000_add_object_size_and_stats.sql (9.03ms)21532026/09/22 08:43:12 OK 20241026095416_initial_model.sql (91.03ms)21542026/09/22 08:43:12 OK 20251210153512_drop_unused_gin_index.sql (7.06ms)21552026/09/22 08:43:12 OK 20251218171726_add_pins.sql (7.73ms)21562026/09/22 08:43:12 OK 20260905000000_add_claims.sql (21.48ms)21572026/09/22 08:43:12 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=431.752606ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/objects/present21582026/09/22 08:43:12 OK 20260920000000_drop_claims.sql (8.03ms)21592026/09/22 08:43:12 goose: successfully migrated database to version: 2026092000000021602026/09/22 08:43:12 OK 20260628120000_add_object_size_and_stats.sql (14.84ms)21612026/09/22 08:43:12 OK 1_commit_pending_closure.sql (3.15ms)21622026/09/22 08:43:12 OK 2_object_stats_trigger.sql (625.29µs)21632026/09/22 08:43:12 goose: up to current file version: 221642026/09/22 08:43:12 OK 20260905000000_add_claims.sql (26.2ms)21652026/09/22 08:43:12 OK 20260920000000_drop_claims.sql (6.91ms)21662026/09/22 08:43:12 goose: successfully migrated database to version: 2026092000000021672026/09/22 08:43:12 OK 1_commit_pending_closure.sql (3.34ms)21682026/09/22 08:43:12 OK 2_object_stats_trigger.sql (761.29µs)21692026/09/22 08:43:12 goose: up to current file version: 22170=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token2171=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token2172=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected2173=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected2174=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected2175=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected2176=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2177=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2178=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token2179=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected21802026/09/22 08:43:12 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]2181=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2182=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected21832026/09/22 08:43:12 WARN Authentication failed token_preview=eyJhbGciOi...MP1YOfSbvg token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]2184--- PASS: TestService_AuthMiddleware_OIDC (1.38s)2185 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)2186 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)2187 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.01s)2188 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.01s)2189--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (1.22s)21902026-09-22 08:43:12.764 UTC [66204] ERROR: relation "goose_db_version" does not exist at character 3621912026-09-22 08:43:12.764 UTC [66204] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC21922026-09-22 08:43:12.797 UTC [66205] ERROR: relation "goose_db_version" does not exist at character 3621932026-09-22 08:43:12.797 UTC [66205] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC21942026/09/22 08:43:12 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=795.112328ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/objects/present21952026/09/22 08:43:12 OK 20241026095416_initial_model.sql (71.02ms)21962026/09/22 08:43:12 INFO Received complete multipart upload request method=POST path=/api/multipart/complete21972026/09/22 08:43:12 OK 20251210153512_drop_unused_gin_index.sql (7.3ms)21982026/09/22 08:43:12 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst2199--- PASS: TestCompleteMultipartUnregistered (1.39s)22002026/09/22 08:43:12 OK 20251218171726_add_pins.sql (10.42ms)22012026/09/22 08:43:12 OK 20260628120000_add_object_size_and_stats.sql (13.22ms)22022026/09/22 08:43:12 OK 20241026095416_initial_model.sql (58.3ms)22032026/09/22 08:43:12 OK 20251210153512_drop_unused_gin_index.sql (1.35ms)22042026/09/22 08:43:12 OK 20260905000000_add_claims.sql (4.32ms)22052026/09/22 08:43:12 OK 20260920000000_drop_claims.sql (2.42ms)22062026/09/22 08:43:12 goose: successfully migrated database to version: 2026092000000022072026/09/22 08:43:12 OK 20251218171726_add_pins.sql (3.08ms)22082026/09/22 08:43:12 OK 1_commit_pending_closure.sql (3.34ms)22092026/09/22 08:43:12 OK 20260628120000_add_object_size_and_stats.sql (3.6ms)22102026/09/22 08:43:12 OK 2_object_stats_trigger.sql (723.88µs)22112026/09/22 08:43:12 goose: up to current file version: 222122026/09/22 08:43:12 OK 20260905000000_add_claims.sql (3.86ms)22132026/09/22 08:43:12 OK 20260920000000_drop_claims.sql (6.7ms)22142026/09/22 08:43:12 goose: successfully migrated database to version: 2026092000000022152026/09/22 08:43:12 OK 1_commit_pending_closure.sql (2.56ms)22162026/09/22 08:43:12 OK 2_object_stats_trigger.sql (515.92µs)22172026/09/22 08:43:12 goose: up to current file version: 222182026/09/22 08:43:13 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=02219=== NAME TestClientIntegration2220 client_integration_test.go:323: Objects in database after GC:2221 client_integration_test.go:323: Successfully deleted all objects with GC --force2222--- PASS: TestClientIntegration (4.51s)22232026/09/22 08:43:13 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"22242026/09/22 08:43:13 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"22252026/09/22 08:43:13 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"22262026/09/22 08:43:13 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.526434251s error="Post \"http://localhost:19999/api/objects/present\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/objects/present22272026/09/22 08:43:15 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-config22282026/09/22 08:43:15 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=200.255852ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22292026/09/22 08:43:15 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=404.378512ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22302026/09/22 08:43:15 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=844.08056ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22312026/09/22 08:43:16 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.504796502s error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22322026/09/22 08:43:18 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"22332026/09/22 08:43:18 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_closures22342026/09/22 08:43:18 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=195.523418ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22352026/09/22 08:43:18 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=408.951845ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22362026/09/22 08:43:19 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=808.323801ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22372026/09/22 08:43:19 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.454775483s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2238--- PASS: TestClientErrorHandling (0.00s)2239 --- PASS: TestClientErrorHandling/InvalidStorePath (1.18s)2240 --- PASS: TestClientErrorHandling/InvalidAuthToken (1.27s)2241 --- PASS: TestClientErrorHandling/ServerNotAvailable (9.43s)2242PASS2243{"timestamp":"2026-09-22T08:43:21.384192Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:52700","error_kind":"io_error","error":"Cancelled","result":"transport_error","target":"rustfs::server::http","filename":"rustfs/src/server/http.rs","line_number":2260,"threadName":"rustfs-worker","threadId":"ThreadId(5)"}22442026-09-22 08:43:21.483 UTC [65876] LOG: received smart shutdown request22452026-09-22 08:43:21.484 UTC [65876] LOG: background worker "logical replication launcher" (PID 65886) exited with exit code 122462026-09-22 08:43:21.492 UTC [65881] LOG: shutting down22472026-09-22 08:43:21.492 UTC [65881] LOG: checkpoint starting: shutdown immediate22482026-09-22 08:43:22.594 UTC [65881] LOG: checkpoint complete: wrote 13223 buffers (80.7%), wrote 3 SLRU buffers; 0 WAL file(s) added, 0 removed, 16 recycled; write=0.754 s, sync=0.320 s, total=1.103 s; sync files=19072, longest=0.001 s, average=0.001 s; distance=264768 kB, estimate=264768 kB; lsn=0/11A1D198, redo lsn=0/11A1D19822492026-09-22 08:43:22.599 UTC [65876] LOG: database system is shut down2250Running OIDC tests...2251=== RUN TestAudienceForIssuer2252=== PAUSE TestAudienceForIssuer2253=== RUN TestGlobMatch2254=== PAUSE TestGlobMatch2255=== RUN TestValidateToken_ValidToken2256=== PAUSE TestValidateToken_ValidToken2257=== RUN TestValidateToken_WrongAudience2258=== PAUSE TestValidateToken_WrongAudience2259=== RUN TestValidateToken_Expired2260=== PAUSE TestValidateToken_Expired2261=== RUN TestValidateToken_BoundClaimsMismatch2262=== PAUSE TestValidateToken_BoundClaimsMismatch2263=== RUN TestValidateToken_BoundSubjectMismatch2264=== PAUSE TestValidateToken_BoundSubjectMismatch2265=== RUN TestValidateToken_MultipleProviders2266=== PAUSE TestValidateToken_MultipleProviders2267=== RUN TestValidateToken_NoMatchingProvider2268=== PAUSE TestValidateToken_NoMatchingProvider2269=== RUN TestValidateToken_KubernetesServiceAccount2270=== PAUSE TestValidateToken_KubernetesServiceAccount2271=== RUN TestNewValidator_KubernetesRequiresCA2272=== PAUSE TestNewValidator_KubernetesRequiresCA2273=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2274=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2275=== RUN TestPins_ReservedForMatchingRule2276=== PAUSE TestPins_ReservedForMatchingRule2277=== RUN TestPins_TopLevelShorthand2278=== PAUSE TestPins_TopLevelShorthand2279=== RUN TestPins_ConfigValidation2280=== PAUSE TestPins_ConfigValidation2281=== RUN TestScopes_LegacyProviderDefaultsToWrite2282=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2283=== RUN TestScopes_Rules2284=== PAUSE TestScopes_Rules2285=== RUN TestScopes_ConfigValidation2286=== PAUSE TestScopes_ConfigValidation2287=== CONT TestAudienceForIssuer2288--- PASS: TestAudienceForIssuer (0.00s)2289=== CONT TestValidateToken_Expired2290=== CONT TestValidateToken_BoundClaimsMismatch2291=== CONT TestValidateToken_KubernetesServiceAccount2292=== CONT TestScopes_ConfigValidation2293=== CONT TestScopes_Rules2294=== CONT TestScopes_LegacyProviderDefaultsToWrite2295=== CONT TestPins_ConfigValidation2296--- PASS: TestPins_ConfigValidation (0.00s)2297=== CONT TestNewValidator_KubernetesRequiresCA2298=== CONT TestPins_TopLevelShorthand2299--- PASS: TestScopes_ConfigValidation (0.01s)2300=== CONT TestValidateToken_ValidToken2301=== CONT TestPins_ReservedForMatchingRule2302=== CONT TestValidateToken_KubernetesIssuerFromOwnToken23032026/09/22 08:43:23 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:52872/oidc2304--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.03s)2305=== CONT TestValidateToken_WrongAudience23062026/09/22 08:43:23 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:52874/oidc2307--- PASS: TestValidateToken_ValidToken (0.02s)2308=== CONT TestGlobMatch2309=== RUN TestGlobMatch/foo_foo2310=== PAUSE TestGlobMatch/foo_foo2311=== RUN TestGlobMatch/foo_bar2312=== PAUSE TestGlobMatch/foo_bar2313=== RUN TestGlobMatch/*_2314=== PAUSE TestGlobMatch/*_2315=== RUN TestGlobMatch/*_anything2316=== PAUSE TestGlobMatch/*_anything2317=== RUN TestGlobMatch/foo*_foo2318=== PAUSE TestGlobMatch/foo*_foo2319=== RUN TestGlobMatch/foo*_foobar2320=== PAUSE TestGlobMatch/foo*_foobar2321=== RUN TestGlobMatch/foo*_bar2322=== PAUSE TestGlobMatch/foo*_bar2323=== RUN TestGlobMatch/*bar_bar2324=== PAUSE TestGlobMatch/*bar_bar2325=== RUN TestGlobMatch/*bar_foobar2326=== PAUSE TestGlobMatch/*bar_foobar2327=== RUN TestGlobMatch/*bar_foo2328=== PAUSE TestGlobMatch/*bar_foo2329=== RUN TestGlobMatch/foo*bar_foobar2330=== PAUSE TestGlobMatch/foo*bar_foobar2331=== RUN TestGlobMatch/foo*bar_foo123bar2332=== PAUSE TestGlobMatch/foo*bar_foo123bar2333=== RUN TestGlobMatch/foo*bar_foobarbaz2334=== PAUSE TestGlobMatch/foo*bar_foobarbaz2335=== RUN TestGlobMatch/*/*_foo/bar2336=== PAUSE TestGlobMatch/*/*_foo/bar2337=== RUN TestGlobMatch/*/*_foo2338=== PAUSE TestGlobMatch/*/*_foo2339=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2340=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2341=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02342=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02343=== RUN TestGlobMatch/refs/*/main_refs/heads/main2344=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2345=== RUN TestGlobMatch/fo?_foo2346=== PAUSE TestGlobMatch/fo?_foo2347=== RUN TestGlobMatch/fo?_fo2348=== PAUSE TestGlobMatch/fo?_fo2349=== RUN TestGlobMatch/fo?_fooo2350=== PAUSE TestGlobMatch/fo?_fooo2351=== RUN TestGlobMatch/?oo_foo2352=== PAUSE TestGlobMatch/?oo_foo2353=== RUN TestGlobMatch/?oo_boo2354=== PAUSE TestGlobMatch/?oo_boo2355=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2356=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2357=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2358=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2359=== CONT TestValidateToken_BoundSubjectMismatch23602026/09/22 08:43:23 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:52876/oidc2361--- PASS: TestValidateToken_Expired (0.04s)2362=== CONT TestValidateToken_NoMatchingProvider23632026/09/22 08:43:23 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:52878/oidc2364--- PASS: TestPins_TopLevelShorthand (0.04s)2365=== CONT TestValidateToken_MultipleProviders23662026/09/22 08:43:23 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:52880/oidc2367--- PASS: TestValidateToken_BoundClaimsMismatch (0.06s)2368=== CONT TestGlobMatch/foo_foo2369=== CONT TestGlobMatch/foo*bar_foobarbaz2370=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2371=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2372=== CONT TestGlobMatch/?oo_boo2373=== CONT TestGlobMatch/?oo_foo2374=== CONT TestGlobMatch/fo?_fooo2375=== CONT TestGlobMatch/fo?_fo2376=== CONT TestGlobMatch/fo?_foo2377=== CONT TestGlobMatch/refs/*/main_refs/heads/main2378=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02379=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2380=== CONT TestGlobMatch/*/*_foo2381=== CONT TestGlobMatch/*/*_foo/bar2382=== CONT TestGlobMatch/*_2383=== CONT TestGlobMatch/foo*_foo2384=== CONT TestGlobMatch/*_anything2385=== CONT TestGlobMatch/foo_bar2386=== CONT TestGlobMatch/*bar_foo2387=== CONT TestGlobMatch/foo*bar_foo123bar2388=== CONT TestGlobMatch/foo*bar_foobar2389=== CONT TestGlobMatch/*bar_foobar2390=== CONT TestGlobMatch/foo*_bar2391=== CONT TestGlobMatch/*bar_bar2392=== CONT TestGlobMatch/foo*_foobar2393--- PASS: TestGlobMatch (0.00s)2394 --- PASS: TestGlobMatch/foo_foo (0.00s)2395 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2396 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2397 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2398 --- PASS: TestGlobMatch/?oo_boo (0.00s)2399 --- PASS: TestGlobMatch/?oo_foo (0.00s)2400 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2401 --- PASS: TestGlobMatch/fo?_fo (0.00s)2402 --- PASS: TestGlobMatch/fo?_foo (0.00s)2403 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2404 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2405 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2406 --- PASS: TestGlobMatch/*/*_foo (0.00s)2407 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2408 --- PASS: TestGlobMatch/*_ (0.00s)2409 --- PASS: TestGlobMatch/foo*_foo (0.00s)2410 --- PASS: TestGlobMatch/*_anything (0.00s)2411 --- PASS: TestGlobMatch/foo_bar (0.00s)2412 --- PASS: TestGlobMatch/*bar_foo (0.00s)2413 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2414 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2415 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2416 --- PASS: TestGlobMatch/foo*_bar (0.00s)2417 --- PASS: TestGlobMatch/*bar_bar (0.00s)2418 --- PASS: TestGlobMatch/foo*_foobar (0.00s)24192026/09/22 08:43:23 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:52882/oidc2420--- PASS: TestValidateToken_WrongAudience (0.04s)24212026/09/22 08:43:23 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:5288624222026/09/22 08:43:23 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC1232423--- PASS: TestValidateToken_KubernetesServiceAccount (0.10s)24242026/09/22 08:43:23 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:52890/oidc2425--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.10s)2426--- PASS: TestPins_ReservedForMatchingRule (0.10s)24272026/09/22 08:43:23 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:52894/oidc24282026/09/22 08:43:23 http: TLS handshake error from 127.0.0.1:52893: remote error: tls: bad certificate2429--- PASS: TestNewValidator_KubernetesRequiresCA (0.12s)2430--- PASS: TestScopes_Rules (0.13s)24312026/09/22 08:43:23 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:52885/oidc2432--- PASS: TestValidateToken_NoMatchingProvider (0.10s)24332026/09/22 08:43:23 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:52899/oidc2434--- PASS: TestValidateToken_BoundSubjectMismatch (0.15s)24352026/09/22 08:43:23 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:52884/oidc24362026/09/22 08:43:23 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:52901/oidc2437--- PASS: TestValidateToken_MultipleProviders (0.13s)2438PASS2439Running hook tests...2440=== RUN TestSendPathsEmpty2441=== PAUSE TestSendPathsEmpty2442=== RUN TestQueueEnqueueAndFetch2443=== PAUSE TestQueueEnqueueAndFetch2444=== RUN TestQueueDeduplication2445=== PAUSE TestQueueDeduplication2446=== RUN TestQueueRemove2447=== PAUSE TestQueueRemove2448=== RUN TestQueueFetchBatchLimit2449=== PAUSE TestQueueFetchBatchLimit2450=== RUN TestQueueRetryMovesToBack2451=== PAUSE TestQueueRetryMovesToBack2452=== RUN TestQueueFetchRemoveLifecycle2453=== PAUSE TestQueueFetchRemoveLifecycle2454=== RUN TestQueueConcurrentWriters2455=== PAUSE TestQueueConcurrentWriters2456=== RUN TestQueueRemoveLargeClosure2457=== PAUSE TestQueueRemoveLargeClosure2458=== RUN TestServerClientIntegration2459=== PAUSE TestServerClientIntegration2460=== RUN TestServerQueueError2461=== PAUSE TestServerQueueError2462=== RUN TestGetListenerSocketActivation2463 server_test.go:210: === RUN TestGetListenerSocketActivation2464 --- PASS: TestGetListenerSocketActivation (0.00s)2465 PASS2466 2467--- PASS: TestGetListenerSocketActivation (0.01s)2468=== RUN TestDrainIsolatesPoisonPath2469=== PAUSE TestDrainIsolatesPoisonPath2470=== RUN TestRunNotBlockedByPoisonHead2471=== PAUSE TestRunNotBlockedByPoisonHead2472=== RUN TestDrainGivesUpWhenServerDown2473=== PAUSE TestDrainGivesUpWhenServerDown2474=== RUN TestFailedPathPrunedByLaterClosure2475=== PAUSE TestFailedPathPrunedByLaterClosure2476=== RUN TestWorkerUploadsAndRemoves2477=== PAUSE TestWorkerUploadsAndRemoves2478=== RUN TestWorkerSkipsGCdPaths2479=== PAUSE TestWorkerSkipsGCdPaths2480=== RUN TestWorkerPrunesClosureDeps2481=== PAUSE TestWorkerPrunesClosureDeps2482=== RUN TestDrainTimeout2483=== PAUSE TestDrainTimeout2484=== CONT TestSendPathsEmpty2485=== CONT TestServerQueueError2486--- PASS: TestSendPathsEmpty (0.00s)2487=== CONT TestQueueFetchBatchLimit2488=== CONT TestQueueRetryMovesToBack2489=== CONT TestWorkerUploadsAndRemoves2490=== CONT TestDrainTimeout2491=== CONT TestServerClientIntegration2492=== CONT TestQueueRemove2493=== CONT TestQueueDeduplication2494=== CONT TestQueueEnqueueAndFetch2495=== CONT TestQueueRemoveLargeClosure24962026/09/22 08:43:24 ERROR Failed to queue paths error="permission denied" count=12497--- PASS: TestServerQueueError (0.00s)2498=== CONT TestQueueConcurrentWriters2499--- PASS: TestServerClientIntegration (0.00s)2500=== CONT TestQueueFetchRemoveLifecycle2501--- PASS: TestQueueFetchBatchLimit (0.01s)2502=== CONT TestWorkerPrunesClosureDeps25032026/09/22 08:43:24 INFO Upload queue status pending=225042026/09/22 08:43:24 INFO Uploading batch count=225052026/09/22 08:43:24 INFO Uploading batch count=22506--- PASS: TestQueueEnqueueAndFetch (0.01s)2507=== CONT TestWorkerSkipsGCdPaths2508--- PASS: TestQueueDeduplication (0.01s)2509=== CONT TestDrainGivesUpWhenServerDown2510--- PASS: TestQueueFetchRemoveLifecycle (0.01s)2511=== CONT TestFailedPathPrunedByLaterClosure2512--- PASS: TestQueueRetryMovesToBack (0.01s)2513=== CONT TestRunNotBlockedByPoisonHead2514--- PASS: TestQueueRemove (0.01s)2515=== CONT TestDrainIsolatesPoisonPath25162026/09/22 08:43:24 INFO Upload queue status pending=225172026/09/22 08:43:24 INFO Uploading batch count=125182026/09/22 08:43:24 ERROR Upload failed error="upload failed" count=125192026/09/22 08:43:24 INFO Upload queue status pending=225202026/09/22 08:43:24 WARN Store path no longer exists (garbage collected?), removing from queue path=/nix/var/nix/builds/nix-65797-4283757879/TestWorkerSkipsGCdPaths3093166109/002/nonexistent25212026/09/22 08:43:24 INFO Uploading batch count=125222026/09/22 08:43:24 INFO Uploading batch count=125232026/09/22 08:43:24 INFO Uploading batch count=125242026/09/22 08:43:24 INFO Upload queue status pending=325252026/09/22 08:43:24 INFO Uploading batch count=125262026/09/22 08:43:24 INFO Uploading batch count=125272026/09/22 08:43:24 ERROR Upload failed error="upload failed" count=125282026/09/22 08:43:24 INFO Uploading batch count=225292026/09/22 08:43:24 ERROR Upload failed error="upload failed" count=225302026/09/22 08:43:24 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-65797-4283757879/TestDrainGivesUpWhenServerDown1586685420/002/a25312026/09/22 08:43:24 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-65797-4283757879/TestDrainGivesUpWhenServerDown1586685420/002/b25322026/09/22 08:43:24 INFO Uploading batch count=425332026/09/22 08:43:24 ERROR Upload failed error="upload failed" count=425342026/09/22 08:43:24 INFO Uploading batch count=225352026/09/22 08:43:24 ERROR Upload failed error="upload failed" count=225362026/09/22 08:43:24 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-65797-4283757879/TestDrainGivesUpWhenServerDown1586685420/002/c25372026/09/22 08:43:24 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-65797-4283757879/TestDrainIsolatesPoisonPath3547679434/002/bbb25382026/09/22 08:43:24 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-65797-4283757879/TestDrainGivesUpWhenServerDown1586685420/002/d25392026/09/22 08:43:24 INFO Uploading batch count=225402026/09/22 08:43:24 ERROR Upload failed error="upload failed" count=225412026/09/22 08:43:24 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-65797-4283757879/TestDrainGivesUpWhenServerDown1586685420/002/e25422026/09/22 08:43:24 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-65797-4283757879/TestDrainGivesUpWhenServerDown1586685420/002/f25432026/09/22 08:43:24 INFO Uploading batch count=125442026/09/22 08:43:24 ERROR Upload failed error="upload failed" count=12545--- PASS: TestFailedPathPrunedByLaterClosure (0.00s)25462026/09/22 08:43:24 INFO Uploading batch count=125472026/09/22 08:43:24 ERROR Upload failed error="upload failed" count=125482026/09/22 08:43:24 ERROR Drain finished with paths left in queue remaining=1025492026/09/22 08:43:24 INFO Uploading batch count=125502026/09/22 08:43:24 ERROR Upload failed error="upload failed" count=125512026/09/22 08:43:24 ERROR Drain finished with paths left in queue remaining=12552--- PASS: TestDrainGivesUpWhenServerDown (0.01s)2553--- PASS: TestDrainIsolatesPoisonPath (0.01s)2554--- PASS: TestWorkerUploadsAndRemoves (0.03s)2555--- PASS: TestWorkerPrunesClosureDeps (0.02s)2556--- PASS: TestWorkerSkipsGCdPaths (0.02s)2557--- PASS: TestQueueRemoveLargeClosure (0.06s)2558--- PASS: TestQueueConcurrentWriters (0.15s)25592026/09/22 08:43:24 ERROR Upload failed error="context deadline exceeded" count=225602026/09/22 08:43:24 ERROR Drain finished with paths left in queue remaining=42561--- PASS: TestDrainTimeout (0.21s)25622026/09/22 08:43:25 INFO Uploading batch count=125632026/09/22 08:43:25 INFO Uploading batch count=125642026/09/22 08:43:25 INFO Uploading batch count=125652026/09/22 08:43:25 ERROR Upload failed error="upload failed" count=125662026/09/22 08:43:25 INFO Uploading batch count=125672026/09/22 08:43:25 ERROR Upload failed error="upload failed" count=125682026/09/22 08:43:25 INFO Uploading batch count=125692026/09/22 08:43:25 ERROR Upload failed error="upload failed" count=125702026/09/22 08:43:25 INFO Uploading batch count=125712026/09/22 08:43:25 ERROR Upload failed error="upload failed" count=125722026/09/22 08:43:25 ERROR Drain finished with paths left in queue remaining=12573--- PASS: TestRunNotBlockedByPoisonHead (1.03s)2574PASS