niks3-go-unit-tests
checks.aarch64-darwin.go-unit-tests
· build #266
· raw
1Running client tests...2=== RUN TestDoServerRequestAttachesToken3=== PAUSE TestDoServerRequestAttachesToken4=== RUN TestRegisterUploadedObjectReusesConnections5=== PAUSE TestRegisterUploadedObjectReusesConnections6=== RUN TestCaseHackSuffix7=== PAUSE TestCaseHackSuffix8=== RUN TestFilterOversizedClosures9=== PAUSE TestFilterOversizedClosures10=== RUN TestUploadMultipart_PartsInParallel11=== PAUSE TestUploadMultipart_PartsInParallel12=== RUN TestPartSizeForNAR13=== PAUSE TestPartSizeForNAR14=== RUN TestUploadMultipart_SupersededByPeer15=== PAUSE TestUploadMultipart_SupersededByPeer16=== RUN TestDumpPathCaseHackMatchesNix17--- PASS: TestDumpPathCaseHackMatchesNix (0.05s)18=== RUN TestDumpPathCaseHackCollision19--- PASS: TestDumpPathCaseHackCollision (0.00s)20=== RUN TestDumpPathMatchesNix21=== PAUSE TestDumpPathMatchesNix22=== RUN TestDumpPathSingleFile23=== PAUSE TestDumpPathSingleFile24=== RUN TestDumpPathWriterError25=== PAUSE TestDumpPathWriterError26=== RUN TestEncodeNixBase3227=== PAUSE TestEncodeNixBase3228=== RUN TestEncodeNixBase32WithRealHash29=== PAUSE TestEncodeNixBase32WithRealHash30=== RUN TestConvertHashToNix3231=== PAUSE TestConvertHashToNix3232=== RUN TestGetStorePathHash33=== PAUSE TestGetStorePathHash34=== RUN TestPathInfoHashCompatibility35=== PAUSE TestPathInfoHashCompatibility36=== RUN TestParsePathInfoJSON37=== PAUSE TestParsePathInfoJSON38=== RUN TestParsePathInfoJSONMultiplePaths39=== PAUSE TestParsePathInfoJSONMultiplePaths40=== RUN TestPathInfoCACompatibility41=== PAUSE TestPathInfoCACompatibility42=== RUN TestRateLimiterFeedback43=== PAUSE TestRateLimiterFeedback44=== RUN TestRateLimiterFeedback_400DoesNotCountAsSuccess45=== PAUSE TestRateLimiterFeedback_400DoesNotCountAsSuccess46=== RUN TestResolveStorePath47=== PAUSE TestResolveStorePath48=== RUN TestDoWithRetry_BodyReplayedViaGetBody49=== PAUSE TestDoWithRetry_BodyReplayedViaGetBody50=== RUN TestShellSplit51=== PAUSE TestShellSplit52=== RUN TestShellSplitErrors53=== PAUSE TestShellSplitErrors54=== RUN TestStreamPushReportsEveryPath55=== PAUSE TestStreamPushReportsEveryPath56=== RUN TestStreamPushBatchesUnderLoad57=== PAUSE TestStreamPushBatchesUnderLoad58=== RUN TestStreamPushIsolatesFailures59=== PAUSE TestStreamPushIsolatesFailures60=== RUN TestStreamPushGivesUpOnDeadServer61=== PAUSE TestStreamPushGivesUpOnDeadServer62=== RUN TestStreamPushRequestLine63=== PAUSE TestStreamPushRequestLine64=== RUN TestStreamPushReportsSignatures65=== PAUSE TestStreamPushReportsSignatures66=== RUN TestClientSignaturesByStorePath67=== PAUSE TestClientSignaturesByStorePath68=== RUN TestSetClientTLS69=== PAUSE TestSetClientTLS70=== RUN TestSetClientTLSDoesNotMutateDefaultTransport71=== PAUSE TestSetClientTLSDoesNotMutateDefaultTransport72=== RUN TestSetClientTLSErrors73=== PAUSE TestSetClientTLSErrors74=== RUN TestStaticToken75=== PAUSE TestStaticToken76=== RUN TestFileTokenReadsAndCaches77=== PAUSE TestFileTokenReadsAndCaches78=== RUN TestFileTokenMissing79=== PAUSE TestFileTokenMissing80=== RUN TestFileTokenEmpty81=== PAUSE TestFileTokenEmpty82=== RUN TestScriptTokenNoExpiryRerunsEveryCall83=== PAUSE TestScriptTokenNoExpiryRerunsEveryCall84=== RUN TestScriptTokenCachesUntilRefresh85=== PAUSE TestScriptTokenCachesUntilRefresh86=== RUN TestScriptTokenEmptyToken87=== PAUSE TestScriptTokenEmptyToken88=== RUN TestScriptTokenBadJSON89=== PAUSE TestScriptTokenBadJSON90=== RUN TestScriptTokenScriptFails91=== PAUSE TestScriptTokenScriptFails92=== RUN TestScriptTokenEmptyCommand93=== PAUSE TestScriptTokenEmptyCommand94=== CONT TestDoServerRequestAttachesToken95=== CONT TestShellSplit96=== CONT TestEncodeNixBase32WithRealHash97=== CONT TestDoWithRetry_BodyReplayedViaGetBody98--- PASS: TestShellSplit (0.00s)99=== CONT TestPathInfoHashCompatibility100--- PASS: TestEncodeNixBase32WithRealHash (0.00s)101=== CONT TestConvertHashToNix32102=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)103=== RUN TestConvertHashToNix32/SRI_format_to_Nix32104=== CONT TestResolveStorePath105=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32106=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)107=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess108=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon109=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon110=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI111=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI112=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512113=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512114=== CONT TestSetClientTLSErrors115=== RUN TestConvertHashToNix32/already_Nix32_format116=== PAUSE TestConvertHashToNix32/already_Nix32_format117=== RUN TestConvertHashToNix32/invalid_format118=== PAUSE TestConvertHashToNix32/invalid_format119=== CONT TestPathInfoCACompatibility120=== RUN TestPathInfoCACompatibility/null_ca_field121=== PAUSE TestPathInfoCACompatibility/null_ca_field1222026/09/23 13:23:51 WARN Rate limiter enabled after throttle name=server-test rate=5123=== RUN TestPathInfoCACompatibility/old_string_format_-_text124=== CONT TestRateLimiterFeedback125=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text126=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive127=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive128=== CONT TestParsePathInfoJSONMultiplePaths129=== RUN TestRateLimiterFeedback/429_enables_limiter130=== PAUSE TestRateLimiterFeedback/429_enables_limiter131=== RUN TestRateLimiterFeedback/503_enables_limiter132=== PAUSE TestRateLimiterFeedback/503_enables_limiter133=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter134=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter135=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter136=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter137=== CONT TestScriptTokenEmptyCommand138--- PASS: TestScriptTokenEmptyCommand (0.00s)139=== CONT TestScriptTokenBadJSON140--- PASS: TestResolveStorePath (0.00s)141=== CONT TestScriptTokenEmptyToken142=== CONT TestParsePathInfoJSON143=== RUN TestParsePathInfoJSON/Nix_format144=== PAUSE TestParsePathInfoJSON/Nix_format145=== RUN TestParsePathInfoJSON/Lix_format146=== PAUSE TestParsePathInfoJSON/Lix_format147=== RUN TestParsePathInfoJSON/empty_input148=== RUN TestPathInfoCACompatibility/new_structured_format_-_text149=== PAUSE TestParsePathInfoJSON/empty_input150=== RUN TestParsePathInfoJSON/whitespace_only151=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text152=== PAUSE TestParsePathInfoJSON/whitespace_only153=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths154=== RUN TestParsePathInfoJSON/invalid_JSON155=== CONT TestScriptTokenScriptFails156=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method157=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method158=== PAUSE TestParsePathInfoJSON/invalid_JSON159=== CONT TestScriptTokenCachesUntilRefresh160=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths161=== CONT TestScriptTokenNoExpiryRerunsEveryCall162=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths163=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths164=== CONT TestFileTokenEmpty165--- PASS: TestFileTokenEmpty (0.00s)166=== CONT TestFileTokenMissing167=== RUN TestSetClientTLSErrors/missing_cert_file168--- PASS: TestFileTokenMissing (0.00s)169--- PASS: TestScriptTokenScriptFails (0.00s)170=== CONT TestStaticToken171--- PASS: TestStaticToken (0.00s)172=== CONT TestStreamPushRequestLine1732026/09/23 13:23:51 WARN Rate limiter enabled after throttle name=server-test rate=5174--- PASS: TestDoServerRequestAttachesToken (0.01s)1752026/09/23 13:23:51 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:58298176=== PAUSE TestSetClientTLSErrors/missing_cert_file177=== RUN TestSetClientTLSErrors/missing_key_file178=== PAUSE TestSetClientTLSErrors/missing_key_file179=== RUN TestSetClientTLSErrors/missing_ca_file180=== PAUSE TestSetClientTLSErrors/missing_ca_file181=== RUN TestSetClientTLSErrors/invalid_ca_file182=== PAUSE TestSetClientTLSErrors/invalid_ca_file183=== CONT TestSetClientTLSDoesNotMutateDefaultTransport184=== CONT TestFileTokenReadsAndCaches185=== CONT TestSetClientTLS1862026/09/23 13:23:51 WARN Rate limiter backed off name=server-test rate=51872026/09/23 13:23:51 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:582981882026/09/23 13:23:51 ERROR Upload failed error=boom count=1189--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.01s)190=== CONT TestClientSignaturesByStorePath191--- PASS: TestClientSignaturesByStorePath (0.00s)192=== CONT TestStreamPushReportsSignatures193--- PASS: TestFileTokenReadsAndCaches (0.00s)194=== CONT TestGetStorePathHash195=== RUN TestGetStorePathHash/valid_store_path196=== PAUSE TestGetStorePathHash/valid_store_path197=== RUN TestGetStorePathHash/basename_without_hyphen_should_error1982026/09/23 13:23:51 ERROR Upload failed error=boom count=1199=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error200=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error201=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error202=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error203=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error204=== CONT TestUploadMultipart_SupersededByPeer205=== RUN TestUploadMultipart_SupersededByPeer/exists206=== PAUSE TestUploadMultipart_SupersededByPeer/exists207=== RUN TestUploadMultipart_SupersededByPeer/missing208=== PAUSE TestUploadMultipart_SupersededByPeer/missing209=== CONT TestDumpPathSingleFile210--- PASS: TestStreamPushReportsSignatures (0.00s)211=== CONT TestDumpPathMatchesNix212--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.00s)213=== CONT TestDumpPathWriterError214=== RUN TestSetClientTLS/rejects_connection_without_client_cert215=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert216=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA217=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA218=== RUN TestSetClientTLS/preserves_debug_logging_transport219=== PAUSE TestSetClientTLS/preserves_debug_logging_transport220=== CONT TestStreamPushBatchesUnderLoad221=== CONT TestEncodeNixBase32222=== RUN TestEncodeNixBase32/test_string_hash223--- PASS: TestScriptTokenEmptyToken (0.01s)224=== PAUSE TestEncodeNixBase32/test_string_hash225=== RUN TestEncodeNixBase32/empty_input226=== PAUSE TestEncodeNixBase32/empty_input227=== CONT TestStreamPushGivesUpOnDeadServer2282026/09/23 13:23:51 ERROR Upload failed error="connection refused" count=202292026/09/23 13:23:51 ERROR Server seems unavailable, giving up on batch untried=17230--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)231=== CONT TestStreamPushIsolatesFailures2322026/09/23 13:23:51 ERROR Upload failed error="bad path" count=3233--- PASS: TestStreamPushIsolatesFailures (0.00s)234=== CONT TestStreamPushReportsEveryPath235--- PASS: TestStreamPushReportsEveryPath (0.00s)236=== CONT TestFilterOversizedClosures237=== RUN TestFilterOversizedClosures/no_limit_keeps_everything238=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything239=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped240=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped241=== RUN TestFilterOversizedClosures/all_closures_skipped242=== PAUSE TestFilterOversizedClosures/all_closures_skipped243=== CONT TestPartSizeForNAR244=== RUN TestPartSizeForNAR/zero_stays_at_minimum245=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum246=== RUN TestPartSizeForNAR/small_stays_at_minimum247=== PAUSE TestPartSizeForNAR/small_stays_at_minimum248=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum249=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum250=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts251=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts252=== RUN TestPartSizeForNAR/1_TiB253=== PAUSE TestPartSizeForNAR/1_TiB254=== RUN TestPartSizeForNAR/5_TiB_S3_max_object255=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object256=== RUN TestPartSizeForNAR/capped_at_5_GiB257=== PAUSE TestPartSizeForNAR/capped_at_5_GiB258=== CONT TestUploadMultipart_PartsInParallel259--- PASS: TestScriptTokenBadJSON (0.02s)260=== CONT TestCaseHackSuffix261--- PASS: TestStreamPushRequestLine (0.02s)262=== CONT TestShellSplitErrors263--- PASS: TestShellSplitErrors (0.00s)264=== CONT TestRegisterUploadedObjectReusesConnections265--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.03s)266=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)267=== CONT TestConvertHashToNix32/SRI_format_to_Nix32268=== CONT TestConvertHashToNix32/already_Nix32_format269=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI270=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512271=== CONT TestConvertHashToNix32/invalid_format272--- PASS: TestConvertHashToNix32 (0.00s)273 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)274 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)275 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)276=== CONT TestRateLimiterFeedback/429_enables_limiter2772026/09/23 13:23:51 WARN Rate limiter enabled after throttle name=server-test rate=52782026/09/23 13:23:51 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:583732792026/09/23 13:23:51 WARN Rate limiter backed off name=server-test rate=5280=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter281=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter282--- PASS: TestScriptTokenCachesUntilRefresh (0.04s)283=== CONT TestRateLimiterFeedback/503_enables_limiter284=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon285--- PASS: TestPathInfoHashCompatibility (0.00s)286 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)287 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)288 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)289 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)290=== CONT TestPathInfoCACompatibility/null_ca_field291=== CONT TestParsePathInfoJSON/Nix_format292=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method293=== CONT TestPathInfoCACompatibility/new_structured_format_-_text294=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive295=== CONT TestPathInfoCACompatibility/old_string_format_-_text296--- PASS: TestPathInfoCACompatibility (0.00s)297 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)298 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)299 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)300 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)301 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)3022026/09/23 13:23:51 WARN Rate limiter enabled after throttle name=server-test rate=5303=== CONT TestParsePathInfoJSON/whitespace_only304=== CONT TestParsePathInfoJSON/invalid_JSON305=== CONT TestParsePathInfoJSON/empty_input306=== CONT TestParsePathInfoJSON/Lix_format307--- PASS: TestParsePathInfoJSON (0.00s)308 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)309 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)310 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)311 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)312 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)313=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths314=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths315--- PASS: TestParsePathInfoJSONMultiplePaths (0.00s)316 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)317 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)318=== CONT TestSetClientTLSErrors/missing_cert_file319=== CONT TestSetClientTLSErrors/invalid_ca_file3202026/09/23 13:23:51 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:58379321=== CONT TestSetClientTLSErrors/missing_ca_file322=== CONT TestSetClientTLSErrors/missing_key_file3232026/09/23 13:23:51 WARN Rate limiter backed off name=server-test rate=5324--- PASS: TestRateLimiterFeedback (0.00s)325 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)326 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)327 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)328 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)329=== CONT TestUploadMultipart_SupersededByPeer/exists330--- PASS: TestSetClientTLSErrors (0.01s)331 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)332 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)333 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)334 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)335=== CONT TestGetStorePathHash/valid_store_path336=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error337=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error338=== CONT TestGetStorePathHash/basename_without_hyphen_should_error339--- PASS: TestGetStorePathHash (0.00s)340 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)341 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)342 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)343 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)344=== CONT TestUploadMultipart_SupersededByPeer/missing345--- PASS: TestDumpPathWriterError (0.04s)346=== CONT TestSetClientTLS/rejects_connection_without_client_cert347=== CONT TestSetClientTLS/preserves_debug_logging_transport348--- PASS: TestUploadMultipart_SupersededByPeer (0.00s)349 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)350 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)351=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA352--- PASS: TestRegisterUploadedObjectReusesConnections (0.02s)353=== CONT TestEncodeNixBase32/test_string_hash354=== CONT TestEncodeNixBase32/empty_input355--- PASS: TestEncodeNixBase32 (0.00s)356 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)357 --- PASS: TestEncodeNixBase32/empty_input (0.00s)358=== CONT TestFilterOversizedClosures/no_limit_keeps_everything359=== CONT TestFilterOversizedClosures/all_closures_skipped3602026/09/23 13:23:51 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=50361=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped3622026/09/23 13:23:51 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=2000363--- PASS: TestFilterOversizedClosures (0.00s)364 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)365 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)366 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)367=== CONT TestPartSizeForNAR/zero_stays_at_minimum368=== CONT TestPartSizeForNAR/1_TiB369=== CONT TestPartSizeForNAR/capped_at_5_GiB370=== CONT TestPartSizeForNAR/5_TiB_S3_max_object371=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum372=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts373=== CONT TestPartSizeForNAR/small_stays_at_minimum374--- PASS: TestPartSizeForNAR (0.00s)375 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)376 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)377 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)378 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)379 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)380 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)381 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)3822026/09/23 13:23:51 http: TLS handshake error from 127.0.0.1:58385: remote error: tls: bad certificate383--- PASS: TestSetClientTLS (0.00s)384 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.00s)385 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.00s)386 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.01s)387--- PASS: TestDumpPathSingleFile (0.05s)388--- PASS: TestCaseHackSuffix (0.04s)389--- PASS: TestDumpPathMatchesNix (0.07s)390--- PASS: TestStreamPushBatchesUnderLoad (0.10s)391--- PASS: TestUploadMultipart_PartsInParallel (0.61s)392--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)393PASS394Running server tests...395The files belonging to this database system will be owned by user "_nixbld1".396This user must also own the server process.397398The database cluster will be initialized with locale "C".399The default database encoding has accordingly been set to "SQL_ASCII".400The default text search configuration will be set to "english".401402Data page checksums are enabled.403404creating directory /nix/var/nix/builds/nix-62151-941598581/postgres2025895584/data ... ok405creating subdirectories ... ok406selecting dynamic shared memory implementation ... posix407selecting default "max_connections" ... 100408selecting default "shared_buffers" ... 128MB409selecting default time zone ... UTC410creating configuration files ... ok411running bootstrap script ... ok412performing post-bootstrap initialization ... ok413syncing data to disk ... ok414415initdb: warning: enabling "trust" authentication for local connections416initdb: 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.417418Success. You can now start the database server using:419420 pg_ctl -D /nix/var/nix/builds/nix-62151-941598581/postgres2025895584/data -l logfile start421422/nix/var/nix/builds/nix-62151-941598581/postgres2025895584:5432 - no response4232026-09-23 13:23:53.401 UTC [62188] LOG: starting PostgreSQL 18.6 on aarch64-apple-darwin25.6.0, compiled by clang version 21.1.8, 64-bit4242026-09-23 13:23:53.401 UTC [62188] LOG: listening on Unix socket "/nix/var/nix/builds/nix-62151-941598581/postgres2025895584/.s.PGSQL.5432"4252026-09-23 13:23:53.403 UTC [62195] LOG: database system was shut down at 2026-09-23 13:23:53 UTC4262026-09-23 13:23:53.404 UTC [62188] LOG: database system is ready to accept connections427/nix/var/nix/builds/nix-62151-941598581/postgres2025895584:5432 - accepting connections428{"timestamp":"2026-09-23T13:23:53.618481Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"ee03c91e-8ab2-423b-b343-e2f7bccad642","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(3)"}429=== RUN TestService_AuthMiddleware430=== PAUSE TestService_AuthMiddleware431=== RUN TestService_AuthMiddleware_MTLSProxyHeader432=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader433=== RUN TestService_AuthMiddleware_MTLSBoundSubjects434=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects435=== RUN TestService_ReadAuthMiddleware436=== PAUSE TestService_ReadAuthMiddleware437=== RUN TestService_AuthMiddleware_OIDC438=== PAUSE TestService_AuthMiddleware_OIDC439=== RUN TestService_RequireScope_OIDC440=== PAUSE TestService_RequireScope_OIDC441=== RUN TestService_ReadScope_PublicByDefault442=== PAUSE TestService_ReadScope_PublicByDefault443=== RUN TestCacheConfigHandler444=== PAUSE TestCacheConfigHandler445=== RUN TestCacheStatsHandler446=== PAUSE TestCacheStatsHandler447=== RUN TestClientCADerivations448=== PAUSE TestClientCADerivations449=== RUN TestClientErrorHandling450=== PAUSE TestClientErrorHandling451=== RUN TestClientIntegration452=== PAUSE TestClientIntegration453=== RUN TestClientMultipleUploads454=== PAUSE TestClientMultipleUploads455=== RUN TestClientWithDependencies456=== PAUSE TestClientWithDependencies457=== RUN TestClientSharedPathCommittedMidPush458=== PAUSE TestClientSharedPathCommittedMidPush459=== RUN TestPinProtectsFromGC460=== PAUSE TestPinProtectsFromGC461=== RUN TestClientPushesUseOnePush462=== PAUSE TestClientPushesUseOnePush463=== RUN TestClientFallsBackToClosures464=== PAUSE TestClientFallsBackToClosures465=== RUN TestResolveDBConnectionString466=== PAUSE TestResolveDBConnectionString467=== RUN TestLeadElectsOneAndHandsOver468=== PAUSE TestLeadElectsOneAndHandsOver469=== RUN TestLeadIncumbentWinsAfterRestart4702026-09-23 13:23:53.868 UTC [62225] ERROR: relation "goose_db_version" does not exist at character 364712026-09-23 13:23:53.868 UTC [62225] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC4722026/09/23 13:23:53 OK 20241026095416_initial_model.sql (3.84ms)4732026/09/23 13:23:53 OK 20251210153512_drop_unused_gin_index.sql (388.08µs)4742026/09/23 13:23:53 OK 20251218171726_add_pins.sql (910.04µs)4752026/09/23 13:23:53 OK 20260628120000_add_object_size_and_stats.sql (857.25µs)4762026/09/23 13:23:53 OK 20260905000000_add_claims.sql (974.42µs)4772026/09/23 13:23:53 OK 20260920000000_drop_claims.sql (598.33µs)4782026/09/23 13:23:53 OK 20260923120000_add_pushes.sql (403.67µs)4792026/09/23 13:23:53 goose: successfully migrated database to version: 202609231200004802026/09/23 13:23:53 OK 1_commit_pending_closure.sql (860.79µs)4812026/09/23 13:23:53 OK 2_object_stats_trigger.sql (267.42µs)4822026/09/23 13:23:53 OK 3_commit_push.sql (181.46µs)4832026/09/23 13:23:53 goose: up to current file version: 34842026/09/23 13:23:53 INFO lead: acquired remote=192.0.2.1:12344852026/09/23 13:23:54 INFO lead: released remote=192.0.2.1:12344862026/09/23 13:23:54 INFO lead: acquired remote=192.0.2.1:12344872026/09/23 13:23:54 INFO lead: released remote=192.0.2.1:1234488--- PASS: TestLeadIncumbentWinsAfterRestart (0.87s)489=== RUN TestLeadEndsOnShutdown490=== PAUSE TestLeadEndsOnShutdown491=== RUN TestGCAdvisoryLockBlocksConcurrentRun4922026-09-23 13:23:54.673 UTC [62229] ERROR: relation "goose_db_version" does not exist at character 364932026-09-23 13:23:54.673 UTC [62229] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC4942026/09/23 13:23:54 OK 20241026095416_initial_model.sql (3.68ms)4952026/09/23 13:23:54 OK 20251210153512_drop_unused_gin_index.sql (390.58µs)4962026/09/23 13:23:54 OK 20251218171726_add_pins.sql (833.21µs)4972026/09/23 13:23:54 OK 20260628120000_add_object_size_and_stats.sql (822.71µs)4982026/09/23 13:23:54 OK 20260905000000_add_claims.sql (961.13µs)4992026/09/23 13:23:54 OK 20260920000000_drop_claims.sql (619.63µs)5002026/09/23 13:23:54 OK 20260923120000_add_pushes.sql (409.13µs)5012026/09/23 13:23:54 goose: successfully migrated database to version: 202609231200005022026/09/23 13:23:54 OK 1_commit_pending_closure.sql (866µs)5032026/09/23 13:23:54 OK 2_object_stats_trigger.sql (210.58µs)5042026/09/23 13:23:54 OK 3_commit_push.sql (205.08µs)5052026/09/23 13:23:54 goose: up to current file version: 3506--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.15s)507=== RUN TestGCBugBareHashReferences508=== PAUSE TestGCBugBareHashReferences509=== RUN TestGCMetrics510=== PAUSE TestGCMetrics511=== RUN TestGCTaskStore_StartNew512=== PAUSE TestGCTaskStore_StartNew513=== RUN TestGCTaskStore_DeduplicateSameParams514=== PAUSE TestGCTaskStore_DeduplicateSameParams515=== RUN TestGCTaskStore_ConflictDifferentParams516=== PAUSE TestGCTaskStore_ConflictDifferentParams517=== RUN TestGCTaskStore_GetEmpty518=== PAUSE TestGCTaskStore_GetEmpty519=== RUN TestGCTaskStore_GetReturnsLatest520=== PAUSE TestGCTaskStore_GetReturnsLatest521=== RUN TestGCTaskStore_CompletedAllowsNewTask522=== PAUSE TestGCTaskStore_CompletedAllowsNewTask523=== RUN TestGCTaskStore_PhaseUpdates524=== PAUSE TestGCTaskStore_PhaseUpdates525=== RUN TestGCTaskStore_Fail526=== PAUSE TestGCTaskStore_Fail527=== RUN TestGracefulShutdownDrainsInflight528=== PAUSE TestGracefulShutdownDrainsInflight529=== RUN TestService_healthCheckHandler530=== PAUSE TestService_healthCheckHandler531=== RUN TestService_readinessHandler532=== PAUSE TestService_readinessHandler533=== RUN TestGenerateLandingPage534=== PAUSE TestGenerateLandingPage535=== RUN TestCacheConfigHandlerMaxNarSize536=== PAUSE TestCacheConfigHandlerMaxNarSize537=== RUN TestCreatePendingClosureRejectsOversizedNAR538=== PAUSE TestCreatePendingClosureRejectsOversizedNAR539=== RUN TestNARDeduplicationMetadataUploadBug540=== PAUSE TestNARDeduplicationMetadataUploadBug541=== RUN TestMetricsInventory542=== PAUSE TestMetricsInventory543=== RUN TestService_NativeMTLS544=== PAUSE TestService_NativeMTLS545=== RUN TestServerTLSConfig546=== PAUSE TestServerTLSConfig547=== RUN TestMultipartCleanup548=== PAUSE TestMultipartCleanup549=== RUN TestObjectStatsTrigger550=== PAUSE TestObjectStatsTrigger551=== RUN TestOrphanedObjectsGC552=== PAUSE TestOrphanedObjectsGC553=== RUN TestOrphanedObjectsGCStressTest554=== PAUSE TestOrphanedObjectsGCStressTest555=== RUN TestResurrectedObjectNotDeleted556=== PAUSE TestResurrectedObjectNotDeleted557=== RUN TestCreatePin_ReservedPins558=== PAUSE TestCreatePin_ReservedPins559=== RUN TestParseSingleRange560=== PAUSE TestParseSingleRange561=== RUN TestProxyHeadersOnlyTrustedOnSocket562=== PAUSE TestProxyHeadersOnlyTrustedOnSocket563=== RUN TestIsValidCachePath564=== PAUSE TestIsValidCachePath565=== RUN TestReadProxyNarinfo566=== PAUSE TestReadProxyNarinfo567=== RUN TestReadProxyNarinfoAlreadyDecompressed568=== PAUSE TestReadProxyNarinfoAlreadyDecompressed569=== RUN TestReadProxyNarStreaming570=== PAUSE TestReadProxyNarStreaming571=== RUN TestReadProxy404572=== PAUSE TestReadProxy404573=== RUN TestReadProxyInvalidPath574=== PAUSE TestReadProxyInvalidPath575=== RUN TestReadProxyHead576=== PAUSE TestReadProxyHead577=== RUN TestReadProxyConditionalGet578=== PAUSE TestReadProxyConditionalGet579=== RUN TestReadProxyRootRedirectsToIndexHTML580=== PAUSE TestReadProxyRootRedirectsToIndexHTML581=== RUN TestReadProxyDisabled582=== PAUSE TestReadProxyDisabled583=== RUN TestReadRedirectNar584=== PAUSE TestReadRedirectNar585=== RUN TestReadRedirectKeepsNarinfoProxied586=== PAUSE TestReadRedirectKeepsNarinfoProxied587=== RUN TestReadProxyRangeRequest588=== PAUSE TestReadProxyRangeRequest589=== RUN TestReadRedirectUsesPublicS3URL590=== PAUSE TestReadRedirectUsesPublicS3URL591=== RUN TestPush_OverlappingRootsStoreOneRowPerKey592=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey593=== RUN TestPush_CompleteCommitsEveryRoot594=== PAUSE TestPush_CompleteCommitsEveryRoot595=== RUN TestPush_CommitFailsWhenSkippedKeyWasCollected596=== PAUSE TestPush_CommitFailsWhenSkippedKeyWasCollected597=== RUN TestPush_RejectsBadRequests598=== PAUSE TestPush_RejectsBadRequests599=== RUN TestPush_SignsNarinfosOfItsPendingObjects600=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects601=== RUN TestRedundantMultipartUpload602=== PAUSE TestRedundantMultipartUpload603=== RUN TestCompleteMultipartUpload_ErrorButObjectExists604=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists605=== RUN TestCompletedNarNotReofferedAcrossClosures606=== PAUSE TestCompletedNarNotReofferedAcrossClosures607=== RUN TestPresignedUploadRegisteredBeforeCommit608=== PAUSE TestPresignedUploadRegisteredBeforeCommit609=== RUN TestService_Rustfstest610=== PAUSE TestService_Rustfstest611=== RUN TestParseSize612=== PAUSE TestParseSize613=== RUN TestSkippedUploadsHandler614=== PAUSE TestSkippedUploadsHandler615=== RUN TestSystemdListenerNotActivated616--- PASS: TestSystemdListenerNotActivated (0.00s)617=== RUN TestWatchdogBeatsWhenHealthy618--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)619=== RUN TestWatchdogSkipsWhenUnhealthy6202026/09/23 13:23:54 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6212026/09/23 13:23:54 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6222026/09/23 13:23:54 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6232026/09/23 13:23:54 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6242026/09/23 13:23:54 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6252026/09/23 13:23:54 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6262026/09/23 13:23:54 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6272026/09/23 13:23:54 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6282026/09/23 13:23:54 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6292026/09/23 13:23:54 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"630--- PASS: TestWatchdogSkipsWhenUnhealthy (0.21s)631=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle632=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle633=== RUN TestProxyWriteTimeout634=== PAUSE TestProxyWriteTimeout635=== RUN TestIsValidUploadKey636=== PAUSE TestIsValidUploadKey637=== RUN TestUploadHandlersRejectInvalidKeys638=== PAUSE TestUploadHandlersRejectInvalidKeys639=== RUN TestUploadHandlersRejectOversizedBody640=== PAUSE TestUploadHandlersRejectOversizedBody641=== RUN TestService_cleanupPendingClosuresHandler642=== PAUSE TestService_cleanupPendingClosuresHandler643=== RUN TestService_createPendingClosureHandler644=== PAUSE TestService_createPendingClosureHandler645=== RUN TestService_verifyS3Integrity646=== PAUSE TestService_verifyS3Integrity647=== RUN TestCompleteMultipartUnregistered648=== PAUSE TestCompleteMultipartUnregistered649=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT650=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT651=== CONT TestPush_CompleteCommitsEveryRoot652=== CONT TestService_AuthMiddleware653=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle654=== CONT TestCompletedNarNotReofferedAcrossClosures655=== CONT TestParseSize656=== CONT TestService_healthCheckHandler657=== CONT TestClientPushesUseOnePush658--- PASS: TestParseSize (0.00s)659=== CONT TestSkippedUploadsHandler660=== CONT TestCacheStatsHandler661=== CONT TestCacheConfigHandler662=== CONT TestService_ReadScope_PublicByDefault663=== RUN TestCacheConfigHandler/full_config,_no_issuer664=== PAUSE TestCacheConfigHandler/full_config,_no_issuer665=== RUN TestCacheConfigHandler/no_cache_url_configured666=== PAUSE TestCacheConfigHandler/no_cache_url_configured667=== RUN TestCacheConfigHandler/no_signing_keys668=== PAUSE TestCacheConfigHandler/no_signing_keys669=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator670=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator671=== CONT TestService_RequireScope_OIDC6722026/09/23 13:23:54 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000673--- PASS: TestSkippedUploadsHandler (0.02s)674=== CONT TestService_AuthMiddleware_OIDC6752026/09/23 13:23:55 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:58402/oidc6762026/09/23 13:23:55 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:58404/oidc6772026-09-23 13:23:55.281 UTC [62251] ERROR: relation "goose_db_version" does not exist at character 366782026-09-23 13:23:55.281 UTC [62251] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6792026-09-23 13:23:55.281 UTC [62252] ERROR: relation "goose_db_version" does not exist at character 366802026-09-23 13:23:55.281 UTC [62252] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6812026-09-23 13:23:55.285 UTC [62254] ERROR: relation "goose_db_version" does not exist at character 366822026-09-23 13:23:55.285 UTC [62254] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6832026-09-23 13:23:55.286 UTC [62255] ERROR: relation "goose_db_version" does not exist at character 366842026-09-23 13:23:55.286 UTC [62255] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6852026-09-23 13:23:55.286 UTC [62256] ERROR: relation "goose_db_version" does not exist at character 366862026-09-23 13:23:55.286 UTC [62256] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6872026-09-23 13:23:55.286 UTC [62253] ERROR: relation "goose_db_version" does not exist at character 366882026-09-23 13:23:55.286 UTC [62253] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6892026-09-23 13:23:55.287 UTC [62257] ERROR: relation "goose_db_version" does not exist at character 366902026-09-23 13:23:55.287 UTC [62257] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6912026-09-23 13:23:55.287 UTC [62258] ERROR: relation "goose_db_version" does not exist at character 366922026-09-23 13:23:55.287 UTC [62258] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6932026-09-23 13:23:55.287 UTC [62259] ERROR: relation "goose_db_version" does not exist at character 366942026-09-23 13:23:55.287 UTC [62259] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6952026-09-23 13:23:55.288 UTC [62260] ERROR: relation "goose_db_version" does not exist at character 366962026-09-23 13:23:55.288 UTC [62260] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6972026/09/23 13:23:55 OK 20241026095416_initial_model.sql (5.73ms)6982026/09/23 13:23:55 OK 20251210153512_drop_unused_gin_index.sql (532.5µs)6992026/09/23 13:23:55 OK 20251218171726_add_pins.sql (2.48ms)7002026/09/23 13:23:55 OK 20241026095416_initial_model.sql (6.98ms)7012026/09/23 13:23:55 OK 20251210153512_drop_unused_gin_index.sql (1ms)7022026/09/23 13:23:55 OK 20260628120000_add_object_size_and_stats.sql (2.28ms)7032026/09/23 13:23:55 OK 20241026095416_initial_model.sql (7.33ms)7042026/09/23 13:23:55 OK 20241026095416_initial_model.sql (7.01ms)7052026/09/23 13:23:55 OK 20241026095416_initial_model.sql (7.59ms)7062026/09/23 13:23:55 OK 20251218171726_add_pins.sql (3.03ms)7072026/09/23 13:23:55 OK 20251210153512_drop_unused_gin_index.sql (700.96µs)7082026/09/23 13:23:55 OK 20251210153512_drop_unused_gin_index.sql (551.08µs)7092026/09/23 13:23:55 OK 20241026095416_initial_model.sql (7.43ms)7102026/09/23 13:23:55 OK 20251210153512_drop_unused_gin_index.sql (649.04µs)7112026/09/23 13:23:55 OK 20241026095416_initial_model.sql (10.43ms)7122026/09/23 13:23:55 OK 20260905000000_add_claims.sql (3.22ms)7132026/09/23 13:23:55 OK 20241026095416_initial_model.sql (7.94ms)7142026/09/23 13:23:55 OK 20251210153512_drop_unused_gin_index.sql (759µs)7152026/09/23 13:23:55 OK 20241026095416_initial_model.sql (7.47ms)7162026/09/23 13:23:55 OK 20251210153512_drop_unused_gin_index.sql (610.08µs)7172026/09/23 13:23:55 OK 20251218171726_add_pins.sql (1.32ms)7182026/09/23 13:23:55 OK 20251210153512_drop_unused_gin_index.sql (759.13µs)7192026/09/23 13:23:55 OK 20260628120000_add_object_size_and_stats.sql (1.6ms)7202026/09/23 13:23:55 OK 20260920000000_drop_claims.sql (1.01ms)7212026/09/23 13:23:55 OK 20251210153512_drop_unused_gin_index.sql (618.04µs)7222026/09/23 13:23:55 OK 20251218171726_add_pins.sql (2.27ms)7232026/09/23 13:23:55 OK 20251218171726_add_pins.sql (1.54ms)7242026/09/23 13:23:55 OK 20251218171726_add_pins.sql (1.21ms)7252026/09/23 13:23:55 OK 20251218171726_add_pins.sql (2.33ms)7262026/09/23 13:23:55 OK 20260923120000_add_pushes.sql (1.03ms)7272026/09/23 13:23:55 goose: successfully migrated database to version: 202609231200007282026/09/23 13:23:55 OK 20241026095416_initial_model.sql (7.78ms)7292026/09/23 13:23:55 OK 20260905000000_add_claims.sql (1.59ms)7302026/09/23 13:23:55 OK 20260628120000_add_object_size_and_stats.sql (1.87ms)7312026/09/23 13:23:55 OK 20251218171726_add_pins.sql (1.79ms)7322026/09/23 13:23:55 OK 20251218171726_add_pins.sql (1.43ms)7332026/09/23 13:23:55 OK 20251210153512_drop_unused_gin_index.sql (635.54µs)7342026/09/23 13:23:55 OK 20260628120000_add_object_size_and_stats.sql (1.34ms)7352026/09/23 13:23:55 OK 1_commit_pending_closure.sql (1.11ms)7362026/09/23 13:23:55 OK 20260628120000_add_object_size_and_stats.sql (1.46ms)7372026/09/23 13:23:55 OK 20260628120000_add_object_size_and_stats.sql (2.2ms)7382026/09/23 13:23:55 OK 20260920000000_drop_claims.sql (1.33ms)7392026/09/23 13:23:55 OK 2_object_stats_trigger.sql (457.92µs)7402026/09/23 13:23:55 OK 20260628120000_add_object_size_and_stats.sql (1.21ms)7412026/09/23 13:23:55 OK 20260628120000_add_object_size_and_stats.sql (1.35ms)7422026/09/23 13:23:55 OK 3_commit_push.sql (329.46µs)7432026/09/23 13:23:55 goose: up to current file version: 37442026/09/23 13:23:55 OK 20260628120000_add_object_size_and_stats.sql (2.27ms)7452026/09/23 13:23:55 OK 20260923120000_add_pushes.sql (954.5µs)7462026/09/23 13:23:55 goose: successfully migrated database to version: 202609231200007472026/09/23 13:23:55 OK 20260905000000_add_claims.sql (2.67ms)7482026/09/23 13:23:55 OK 20260905000000_add_claims.sql (2.18ms)7492026/09/23 13:23:55 OK 20251218171726_add_pins.sql (2.5ms)7502026/09/23 13:23:55 OK 20260905000000_add_claims.sql (2.25ms)7512026/09/23 13:23:55 OK 20260905000000_add_claims.sql (1.92ms)7522026/09/23 13:23:55 OK 20260905000000_add_claims.sql (2.05ms)7532026/09/23 13:23:55 OK 20260905000000_add_claims.sql (2.14ms)7542026/09/23 13:23:55 OK 20260920000000_drop_claims.sql (1.05ms)7552026/09/23 13:23:55 OK 1_commit_pending_closure.sql (1.66ms)7562026/09/23 13:23:55 OK 20260905000000_add_claims.sql (2.62ms)7572026/09/23 13:23:55 OK 20260920000000_drop_claims.sql (1.12ms)7582026/09/23 13:23:55 OK 2_object_stats_trigger.sql (374.5µs)7592026/09/23 13:23:55 OK 20260923120000_add_pushes.sql (581.29µs)7602026/09/23 13:23:55 goose: successfully migrated database to version: 202609231200007612026/09/23 13:23:55 OK 20260628120000_add_object_size_and_stats.sql (1.63ms)7622026/09/23 13:23:55 OK 3_commit_push.sql (498.38µs)7632026/09/23 13:23:55 goose: up to current file version: 37642026/09/23 13:23:55 OK 20260920000000_drop_claims.sql (948.63µs)7652026/09/23 13:23:55 OK 20260923120000_add_pushes.sql (870µs)7662026/09/23 13:23:55 goose: successfully migrated database to version: 202609231200007672026/09/23 13:23:55 OK 20260920000000_drop_claims.sql (1.63ms)7682026/09/23 13:23:55 OK 20260920000000_drop_claims.sql (1.41ms)7692026/09/23 13:23:55 OK 20260920000000_drop_claims.sql (1.8ms)7702026/09/23 13:23:55 OK 20260920000000_drop_claims.sql (1.07ms)7712026/09/23 13:23:55 OK 1_commit_pending_closure.sql (1.1ms)7722026/09/23 13:23:55 OK 2_object_stats_trigger.sql (175.79µs)7732026/09/23 13:23:55 OK 1_commit_pending_closure.sql (881.08µs)7742026/09/23 13:23:55 OK 3_commit_push.sql (176.96µs)7752026/09/23 13:23:55 goose: up to current file version: 37762026/09/23 13:23:55 OK 2_object_stats_trigger.sql (216.33µs)7772026/09/23 13:23:55 OK 3_commit_push.sql (183.42µs)7782026/09/23 13:23:55 goose: up to current file version: 37792026/09/23 13:23:55 OK 20260923120000_add_pushes.sql (6.94ms)7802026/09/23 13:23:55 goose: successfully migrated database to version: 202609231200007812026/09/23 13:23:55 OK 20260923120000_add_pushes.sql (6.91ms)7822026/09/23 13:23:55 goose: successfully migrated database to version: 202609231200007832026/09/23 13:23:55 OK 20260923120000_add_pushes.sql (7.04ms)7842026/09/23 13:23:55 goose: successfully migrated database to version: 202609231200007852026/09/23 13:23:55 OK 20260923120000_add_pushes.sql (7.16ms)7862026/09/23 13:23:55 goose: successfully migrated database to version: 202609231200007872026/09/23 13:23:55 OK 20260923120000_add_pushes.sql (7.37ms)7882026/09/23 13:23:55 goose: successfully migrated database to version: 202609231200007892026/09/23 13:23:55 OK 1_commit_pending_closure.sql (768.04µs)7902026/09/23 13:23:55 OK 1_commit_pending_closure.sql (711.96µs)7912026/09/23 13:23:55 OK 1_commit_pending_closure.sql (816.75µs)7922026/09/23 13:23:55 OK 2_object_stats_trigger.sql (228.88µs)7932026/09/23 13:23:55 OK 2_object_stats_trigger.sql (292.83µs)7942026/09/23 13:23:55 OK 1_commit_pending_closure.sql (833.17µs)7952026/09/23 13:23:55 OK 2_object_stats_trigger.sql (221.58µs)7962026/09/23 13:23:55 OK 1_commit_pending_closure.sql (991.83µs)7972026/09/23 13:23:55 OK 3_commit_push.sql (216µs)7982026/09/23 13:23:55 goose: up to current file version: 37992026/09/23 13:23:55 OK 3_commit_push.sql (221.67µs)8002026/09/23 13:23:55 goose: up to current file version: 38012026/09/23 13:23:55 OK 2_object_stats_trigger.sql (225.5µs)8022026/09/23 13:23:55 OK 3_commit_push.sql (181.38µs)8032026/09/23 13:23:55 goose: up to current file version: 38042026/09/23 13:23:55 OK 2_object_stats_trigger.sql (205.83µs)8052026/09/23 13:23:55 OK 3_commit_push.sql (155.79µs)8062026/09/23 13:23:55 goose: up to current file version: 38072026/09/23 13:23:55 OK 3_commit_push.sql (180µs)8082026/09/23 13:23:55 goose: up to current file version: 38092026/09/23 13:23:55 OK 20260905000000_add_claims.sql (29.57ms)8102026/09/23 13:23:55 OK 20260920000000_drop_claims.sql (1.21ms)8112026/09/23 13:23:55 OK 20260923120000_add_pushes.sql (404.96µs)8122026/09/23 13:23:55 goose: successfully migrated database to version: 202609231200008132026/09/23 13:23:55 OK 1_commit_pending_closure.sql (671.08µs)8142026/09/23 13:23:55 OK 2_object_stats_trigger.sql (180µs)8152026/09/23 13:23:55 OK 3_commit_push.sql (180.92µs)8162026/09/23 13:23:55 goose: up to current file version: 38172026/09/23 13:23:55 INFO Received uploads request method=POST path=/api/pending_closures8182026/09/23 13:23:55 INFO Received uploads request method=POST path=/api/pending_closures8192026/09/23 13:23:55 INFO Received complete multipart upload request method=POST path=/api/multipart/complete820--- PASS: TestCacheStatsHandler (0.75s)821=== CONT TestService_ReadAuthMiddleware822=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token823=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token824=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected825=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected826=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected827=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected828=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured829=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured830=== CONT TestService_AuthMiddleware_MTLSBoundSubjects8312026/09/23 13:23:56 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"832--- PASS: TestService_AuthMiddleware (1.11s)833=== CONT TestService_AuthMiddleware_MTLSProxyHeader8342026-09-23 13:23:56.500 UTC [62270] ERROR: relation "goose_db_version" does not exist at character 368352026-09-23 13:23:56.500 UTC [62270] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC836--- PASS: TestService_ReadScope_PublicByDefault (1.52s)837=== CONT TestClientMultipleUploads8382026-09-23 13:23:56.598 UTC [62275] ERROR: relation "goose_db_version" does not exist at character 368392026-09-23 13:23:56.598 UTC [62275] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8402026/09/23 13:23:56 OK 20241026095416_initial_model.sql (60.48ms)8412026/09/23 13:23:56 OK 20251210153512_drop_unused_gin_index.sql (7.52ms)8422026/09/23 13:23:56 OK 20251218171726_add_pins.sql (6.57ms)8432026/09/23 13:23:56 OK 20260628120000_add_object_size_and_stats.sql (22.53ms)8442026/09/23 13:23:56 OK 20260905000000_add_claims.sql (22.26ms)8452026/09/23 13:23:56 OK 20260920000000_drop_claims.sql (16.47ms)8462026/09/23 13:23:56 OK 20260923120000_add_pushes.sql (5.09ms)8472026/09/23 13:23:56 goose: successfully migrated database to version: 202609231200008482026/09/23 13:23:56 OK 1_commit_pending_closure.sql (860.5µs)8492026/09/23 13:23:56 OK 2_object_stats_trigger.sql (235.29µs)8502026/09/23 13:23:56 OK 3_commit_push.sql (213.88µs)8512026/09/23 13:23:56 goose: up to current file version: 38522026/09/23 13:23:56 OK 20241026095416_initial_model.sql (67.45ms)8532026/09/23 13:23:56 OK 20251210153512_drop_unused_gin_index.sql (5.69ms)8542026/09/23 13:23:56 INFO Received push request method=POST path=/api/pushes8552026/09/23 13:23:56 INFO Received uploads request method=POST path=/api/pending_closures8562026/09/23 13:23:56 INFO Received uploads request method=POST path=/api/pending_closures8572026/09/23 13:23:56 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)8582026/09/23 13:23:56 INFO Uploading pkgwc3ijsjflnakg0i7529y4nxq7l5nq-shared-dep (136B)8592026/09/23 13:23:56 INFO Uploading r3iipv1dzv7zmm34w3sbbybybgywg8az-a (248B)8602026/09/23 13:23:56 OK 20251218171726_add_pins.sql (16.98ms)8612026/09/23 13:23:56 WARN Failed to register uploaded object key=pkgwc3ijsjflnakg0i7529y4nxq7l5nq.ls error="server returned 404: 404 page not found\n"8622026/09/23 13:23:56 WARN Failed to register uploaded object key=r3iipv1dzv7zmm34w3sbbybybgywg8az.ls error="server returned 404: 404 page not found\n"8632026/09/23 13:23:56 OK 20260628120000_add_object_size_and_stats.sql (32.98ms)8642026/09/23 13:23:56 WARN Failed to register uploaded object key=nar/0v6cmi5vsmhq66ql6l7yjh7fv5wcqprl42f83llazsa1p6vi70gb.nar.zst error="server returned 404: 404 page not found\n"8652026/09/23 13:23:56 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"8662026/09/23 13:23:56 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign8672026/09/23 13:23:56 WARN Failed to register uploaded object key=iryp4lkzcd5f171q1j2lc9lbi4dv1gqz.ls error="server returned 404: 404 page not found\n"8682026/09/23 13:23:56 INFO Signed narinfos id=1 count=28692026/09/23 13:23:56 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign8702026/09/23 13:23:56 INFO Signed narinfos id=2 count=28712026/09/23 13:23:56 INFO Uploading 4 narinfos8722026/09/23 13:23:56 INFO Received complete push request method=POST path=/api/pushes/1/complete8732026/09/23 13:23:56 WARN Failed to register uploaded object key=r3iipv1dzv7zmm34w3sbbybybgywg8az.narinfo error="server returned 404: 404 page not found\n"874--- PASS: TestPush_CompleteCommitsEveryRoot (1.80s)875=== CONT TestPinProtectsFromGC8762026/09/23 13:23:56 WARN Failed to register uploaded object key=iryp4lkzcd5f171q1j2lc9lbi4dv1gqz.narinfo error="server returned 404: 404 page not found\n"8772026/09/23 13:23:56 WARN Failed to register uploaded object key=pkgwc3ijsjflnakg0i7529y4nxq7l5nq.narinfo error="server returned 404: 404 page not found\n"8782026/09/23 13:23:56 INFO Received complete multipart upload request method=POST path=/api/multipart/complete8792026/09/23 13:23:56 OK 20260905000000_add_claims.sql (72.52ms)8802026/09/23 13:23:56 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete8812026/09/23 13:23:56 WARN Failed to register uploaded object key=pkgwc3ijsjflnakg0i7529y4nxq7l5nq.narinfo error="server returned 404: 404 page not found\n"8822026/09/23 13:23:56 INFO Completed upload id=18832026/09/23 13:23:56 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete8842026/09/23 13:23:56 INFO Completed upload id=28852026/09/23 13:23:56 INFO Upload complete. (206ms)886=== NAME TestClientPushesUseOnePush887 client_pushes_test.go:97: Retrieved narinfo from S3:888 StorePath: /nix/var/nix/builds/nix-62151-941598581/TestClientPushesUseOnePush1372481337/001/store/pkgwc3ijsjflnakg0i7529y4nxq7l5nq-shared-dep889 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst890 Compression: zstd891 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82892 NarSize: 136893 References: 894 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n895 client_pushes_test.go:97: Retrieved narinfo from S3:896 StorePath: /nix/var/nix/builds/nix-62151-941598581/TestClientPushesUseOnePush1372481337/001/store/r3iipv1dzv7zmm34w3sbbybybgywg8az-a897 URL: nar/0v6cmi5vsmhq66ql6l7yjh7fv5wcqprl42f83llazsa1p6vi70gb.nar.zst898 Compression: zstd899 NarHash: sha256:0v6cmi5vsmhq66ql6l7yjh7fv5wcqprl42f83llazsa1p6vi70gb900 NarSize: 248901 References: /nix/var/nix/builds/nix-62151-941598581/TestClientPushesUseOnePush1372481337/001/store/pkgwc3ijsjflnakg0i7529y4nxq7l5nq-shared-dep902 CA: text:sha256:1lcylq123bp0pjz3v9zqffhrygr2j4jsfn2196d78v5251xdbr8f903 client_pushes_test.go:97: Retrieved narinfo from S3:904 StorePath: /nix/var/nix/builds/nix-62151-941598581/TestClientPushesUseOnePush1372481337/001/store/iryp4lkzcd5f171q1j2lc9lbi4dv1gqz-b905 URL: nar/0v6cmi5vsmhq66ql6l7yjh7fv5wcqprl42f83llazsa1p6vi70gb.nar.zst906 Compression: zstd907 NarHash: sha256:0v6cmi5vsmhq66ql6l7yjh7fv5wcqprl42f83llazsa1p6vi70gb908 NarSize: 248909 References: /nix/var/nix/builds/nix-62151-941598581/TestClientPushesUseOnePush1372481337/001/store/pkgwc3ijsjflnakg0i7529y4nxq7l5nq-shared-dep910 CA: text:sha256:1lcylq123bp0pjz3v9zqffhrygr2j4jsfn2196d78v5251xdbr8f911 client_pushes_test.go:100: POST /api/pushes calls = 0, want 1912 client_pushes_test.go:104: POST /api/pending_closures calls = 2, want 09132026/09/23 13:23:56 OK 20260920000000_drop_claims.sql (55.11ms)9142026/09/23 13:23:56 OK 20260923120000_add_pushes.sql (5.05ms)9152026/09/23 13:23:56 goose: successfully migrated database to version: 202609231200009162026/09/23 13:23:56 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=YjI3YWFhNzYtOTcxMi00OTgzLWIwMmMtMjMwNjlmNGUzMmZiLjljYzhlNTZlLWZjMTYtNGFlOS1hZTRjLWI4ZGU0NjkyZmNiZngxNzkwMTY5ODM1NTI5MjA3MDAw parts=129172026/09/23 13:23:56 INFO Received uploads request method=POST path=/api/pending_closures918--- PASS: TestCompletedNarNotReofferedAcrossClosures (1.90s)919=== CONT TestClientSharedPathCommittedMidPush9202026/09/23 13:23:56 OK 1_commit_pending_closure.sql (1.34ms)9212026/09/23 13:23:56 OK 2_object_stats_trigger.sql (669.21µs)9222026/09/23 13:23:56 OK 3_commit_push.sql (273.58µs)9232026/09/23 13:23:56 goose: up to current file version: 3924--- FAIL: TestClientPushesUseOnePush (1.94s)925=== CONT TestClientWithDependencies9262026-09-23 13:23:56.919 UTC [62287] ERROR: relation "goose_db_version" does not exist at character 369272026-09-23 13:23:56.919 UTC [62287] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC928--- PASS: TestService_healthCheckHandler (1.98s)929=== CONT TestPush_SignsNarinfosOfItsPendingObjects9302026/09/23 13:23:57 OK 20241026095416_initial_model.sql (83.85ms)9312026/09/23 13:23:57 OK 20251210153512_drop_unused_gin_index.sql (6.42ms)9322026/09/23 13:23:57 OK 20251218171726_add_pins.sql (7.52ms)9332026/09/23 13:23:57 OK 20260628120000_add_object_size_and_stats.sql (22.64ms)9342026/09/23 13:23:57 OK 20260905000000_add_claims.sql (25.13ms)935=== RUN TestService_RequireScope_OIDC/builder_may_write936=== PAUSE TestService_RequireScope_OIDC/builder_may_write937=== RUN TestService_RequireScope_OIDC/builder_may_not_admin938=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin939=== RUN TestService_RequireScope_OIDC/ops_may_admin940=== PAUSE TestService_RequireScope_OIDC/ops_may_admin941=== RUN TestService_RequireScope_OIDC/ops_may_not_write942=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write943=== RUN TestService_RequireScope_OIDC/reader_may_not_write944=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write945=== RUN TestService_RequireScope_OIDC/static_token_may_admin946=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin947=== RUN TestService_RequireScope_OIDC/static_token_may_write948=== PAUSE TestService_RequireScope_OIDC/static_token_may_write949=== RUN TestService_RequireScope_OIDC/reader_may_read950=== PAUSE TestService_RequireScope_OIDC/reader_may_read951=== RUN TestService_RequireScope_OIDC/writer_implies_read952=== PAUSE TestService_RequireScope_OIDC/writer_implies_read953=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read954=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read955=== CONT TestCompleteMultipartUpload_ErrorButObjectExists9562026/09/23 13:23:57 OK 20260920000000_drop_claims.sql (26.89ms)9572026/09/23 13:23:57 OK 20260923120000_add_pushes.sql (10.94ms)9582026/09/23 13:23:57 goose: successfully migrated database to version: 202609231200009592026/09/23 13:23:57 OK 1_commit_pending_closure.sql (1.51ms)9602026/09/23 13:23:57 OK 2_object_stats_trigger.sql (340.33µs)9612026/09/23 13:23:57 OK 3_commit_push.sql (295.54µs)9622026/09/23 13:23:57 goose: up to current file version: 3963--- PASS: TestService_ReadAuthMiddleware (1.53s)964=== CONT TestRedundantMultipartUpload9652026-09-23 13:23:57.338 UTC [62296] ERROR: relation "goose_db_version" does not exist at character 369662026-09-23 13:23:57.338 UTC [62296] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9672026/09/23 13:23:57 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"9682026/09/23 13:23:57 WARN mTLS auth: bound subjects configured but subject DN unavailable9692026/09/23 13:23:57 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"970--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (1.49s)971=== CONT TestClientErrorHandling972=== RUN TestClientErrorHandling/InvalidStorePath973=== PAUSE TestClientErrorHandling/InvalidStorePath974=== RUN TestClientErrorHandling/InvalidAuthToken975=== PAUSE TestClientErrorHandling/InvalidAuthToken976=== RUN TestClientErrorHandling/ServerNotAvailable977=== PAUSE TestClientErrorHandling/ServerNotAvailable978=== CONT TestClientIntegration9792026/09/23 13:23:57 OK 20241026095416_initial_model.sql (91.67ms)9802026/09/23 13:23:57 OK 20251210153512_drop_unused_gin_index.sql (926.17µs)9812026/09/23 13:23:57 OK 20251218171726_add_pins.sql (41.96ms)9822026/09/23 13:23:57 OK 20260628120000_add_object_size_and_stats.sql (24.34ms)9832026/09/23 13:23:57 OK 20260905000000_add_claims.sql (31.3ms)984--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (1.48s)985=== CONT TestGCTaskStore_DeduplicateSameParams986--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)987=== CONT TestGracefulShutdownDrainsInflight9882026/09/23 13:23:57 INFO Starting HTTP server address=127.0.0.1:584329892026/09/23 13:23:57 INFO Shutdown signal received, draining in-flight requests timeout=10s9902026/09/23 13:23:57 OK 20260920000000_drop_claims.sql (23.13ms)9912026/09/23 13:23:57 OK 20260923120000_add_pushes.sql (14.94ms)9922026/09/23 13:23:57 goose: successfully migrated database to version: 202609231200009932026/09/23 13:23:57 OK 1_commit_pending_closure.sql (4.52ms)9942026/09/23 13:23:57 OK 2_object_stats_trigger.sql (1.24ms)9952026/09/23 13:23:57 OK 3_commit_push.sql (620.63µs)9962026/09/23 13:23:57 goose: up to current file version: 3997--- PASS: TestGracefulShutdownDrainsInflight (0.07s)998=== CONT TestGCTaskStore_Fail999--- PASS: TestGCTaskStore_Fail (0.00s)1000=== CONT TestGCTaskStore_PhaseUpdates1001--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)1002=== CONT TestGCTaskStore_CompletedAllowsNewTask1003--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)1004=== CONT TestGCTaskStore_GetReturnsLatest1005--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)1006=== CONT TestGCTaskStore_GetEmpty1007--- PASS: TestGCTaskStore_GetEmpty (0.00s)1008=== CONT TestGCTaskStore_ConflictDifferentParams1009--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)1010=== CONT TestClientCADerivations10112026-09-23 13:23:57.861 UTC [62302] ERROR: relation "goose_db_version" does not exist at character 3610122026-09-23 13:23:57.861 UTC [62302] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10132026-09-23 13:23:57.861 UTC [62303] ERROR: relation "goose_db_version" does not exist at character 3610142026-09-23 13:23:57.861 UTC [62303] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10152026-09-23 13:23:57.861 UTC [62304] ERROR: relation "goose_db_version" does not exist at character 3610162026-09-23 13:23:57.861 UTC [62304] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10172026-09-23 13:23:57.862 UTC [62305] ERROR: relation "goose_db_version" does not exist at character 3610182026-09-23 13:23:57.862 UTC [62305] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10192026/09/23 13:23:57 OK 20241026095416_initial_model.sql (8.91ms)10202026/09/23 13:23:57 OK 20251210153512_drop_unused_gin_index.sql (501.21µs)10212026/09/23 13:23:57 OK 20251218171726_add_pins.sql (899.92µs)10222026/09/23 13:23:57 OK 20260628120000_add_object_size_and_stats.sql (1.32ms)10232026/09/23 13:23:57 OK 20241026095416_initial_model.sql (35.16ms)10242026/09/23 13:23:57 OK 20260905000000_add_claims.sql (25.43ms)10252026-09-23 13:23:57.907 UTC [62307] ERROR: relation "goose_db_version" does not exist at character 3610262026-09-23 13:23:57.907 UTC [62307] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10272026/09/23 13:23:57 OK 20251210153512_drop_unused_gin_index.sql (862.63µs)10282026/09/23 13:23:57 OK 20241026095416_initial_model.sql (36.26ms)10292026/09/23 13:23:57 OK 20260920000000_drop_claims.sql (1.94ms)10302026/09/23 13:23:57 OK 20241026095416_initial_model.sql (37.27ms)1031=== NAME TestClientMultipleUploads1032 client_integration_test.go:358: Created store path 0: /nix/var/nix/builds/nix-62151-941598581/TestClientMultipleUploads889222638/001/store/s8cgxzj2cy8hra1sza0wahlalhhm065g-test-file-0.txt10332026/09/23 13:23:57 OK 20251218171726_add_pins.sql (2.08ms)10342026/09/23 13:23:57 OK 20251210153512_drop_unused_gin_index.sql (976.79µs)10352026/09/23 13:23:57 OK 20251210153512_drop_unused_gin_index.sql (754.38µs)10362026/09/23 13:23:57 OK 20260923120000_add_pushes.sql (1.45ms)10372026/09/23 13:23:57 goose: successfully migrated database to version: 2026092312000010382026/09/23 13:23:57 OK 20251218171726_add_pins.sql (2.16ms)10392026/09/23 13:23:57 OK 1_commit_pending_closure.sql (1.48ms)10402026/09/23 13:23:57 OK 20251218171726_add_pins.sql (1.94ms)10412026/09/23 13:23:57 OK 2_object_stats_trigger.sql (379.46µs)10422026/09/23 13:23:57 OK 3_commit_push.sql (250.29µs)10432026/09/23 13:23:57 goose: up to current file version: 310442026/09/23 13:23:57 OK 20260628120000_add_object_size_and_stats.sql (4.25ms)10452026/09/23 13:23:57 OK 20260628120000_add_object_size_and_stats.sql (1.83ms)10462026/09/23 13:23:57 OK 20260628120000_add_object_size_and_stats.sql (2.66ms)10472026/09/23 13:23:57 OK 20260905000000_add_claims.sql (10.09ms)10482026/09/23 13:23:57 OK 20260905000000_add_claims.sql (18.65ms)10492026/09/23 13:23:57 OK 20260920000000_drop_claims.sql (9.25ms)10502026/09/23 13:23:57 OK 20260905000000_add_claims.sql (19.69ms)10512026/09/23 13:23:57 OK 20260923120000_add_pushes.sql (916.58µs)10522026/09/23 13:23:57 goose: successfully migrated database to version: 2026092312000010532026/09/23 13:23:57 OK 1_commit_pending_closure.sql (810.92µs)10542026/09/23 13:23:57 OK 2_object_stats_trigger.sql (234.46µs)10552026/09/23 13:23:57 OK 3_commit_push.sql (200.75µs)10562026/09/23 13:23:57 goose: up to current file version: 310572026/09/23 13:23:57 OK 20260920000000_drop_claims.sql (7.5ms)10582026/09/23 13:23:57 OK 20260920000000_drop_claims.sql (13.68ms)10592026/09/23 13:23:57 OK 20260923120000_add_pushes.sql (11.51ms)10602026/09/23 13:23:57 goose: successfully migrated database to version: 2026092312000010612026/09/23 13:23:57 OK 20260923120000_add_pushes.sql (4.99ms)10622026/09/23 13:23:57 goose: successfully migrated database to version: 202609231200001063 client_integration_test.go:358: Created store path 1: /nix/var/nix/builds/nix-62151-941598581/TestClientMultipleUploads889222638/001/store/bdjcq2h4bwvlgd8qw1y8q2cljh3xgz9j-test-file-1.txt10642026/09/23 13:23:57 OK 1_commit_pending_closure.sql (844.21µs)10652026/09/23 13:23:57 OK 1_commit_pending_closure.sql (817.75µs)10662026/09/23 13:23:57 OK 2_object_stats_trigger.sql (241.42µs)10672026/09/23 13:23:57 OK 2_object_stats_trigger.sql (248.92µs)10682026/09/23 13:23:57 OK 3_commit_push.sql (190.25µs)10692026/09/23 13:23:57 goose: up to current file version: 310702026/09/23 13:23:57 OK 3_commit_push.sql (232.88µs)10712026/09/23 13:23:57 goose: up to current file version: 310722026/09/23 13:23:57 OK 20241026095416_initial_model.sql (59.23ms)10732026/09/23 13:23:57 OK 20251210153512_drop_unused_gin_index.sql (6.25ms)10742026/09/23 13:23:57 OK 20251218171726_add_pins.sql (8.09ms)10752026/09/23 13:23:57 OK 20260628120000_add_object_size_and_stats.sql (11.03ms)1076 client_integration_test.go:358: Created store path 2: /nix/var/nix/builds/nix-62151-941598581/TestClientMultipleUploads889222638/001/store/h471z10c0fz3955669wlmja8mn82bc3z-test-file-2.txt10772026/09/23 13:23:58 OK 20260905000000_add_claims.sql (13.66ms)10782026/09/23 13:23:58 OK 20260920000000_drop_claims.sql (1.2ms)10792026/09/23 13:23:58 OK 20260923120000_add_pushes.sql (5.74ms)10802026/09/23 13:23:58 goose: successfully migrated database to version: 2026092312000010812026/09/23 13:23:58 OK 1_commit_pending_closure.sql (1.03ms)10822026/09/23 13:23:58 OK 2_object_stats_trigger.sql (233.54µs)10832026/09/23 13:23:58 OK 3_commit_push.sql (203.08µs)10842026/09/23 13:23:58 goose: up to current file version: 310852026-09-23 13:23:58.052 UTC [62315] ERROR: relation "goose_db_version" does not exist at character 3610862026-09-23 13:23:58.052 UTC [62315] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10872026/09/23 13:23:58 INFO Received push request method=POST path=/api/pushes10882026/09/23 13:23:58 INFO Received uploads request method=POST path=/api/pending_closures10892026/09/23 13:23:58 INFO Received uploads request method=POST path=/api/pending_closures10902026/09/23 13:23:58 INFO Received uploads request method=POST path=/api/pending_closures10912026/09/23 13:23:58 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)10922026/09/23 13:23:58 INFO Uploading h471z10c0fz3955669wlmja8mn82bc3z-test-file-2.txt (160B)10932026/09/23 13:23:58 INFO Uploading bdjcq2h4bwvlgd8qw1y8q2cljh3xgz9j-test-file-1.txt (160B)10942026/09/23 13:23:58 INFO Uploading s8cgxzj2cy8hra1sza0wahlalhhm065g-test-file-0.txt (160B)10952026/09/23 13:23:58 WARN Failed to register uploaded object key=h471z10c0fz3955669wlmja8mn82bc3z.ls error="server returned 404: 404 page not found\n"10962026/09/23 13:23:58 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"10972026/09/23 13:23:58 WARN Failed to register uploaded object key=s8cgxzj2cy8hra1sza0wahlalhhm065g.ls error="server returned 404: 404 page not found\n"10982026/09/23 13:23:58 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"10992026/09/23 13:23:58 WARN Failed to register uploaded object key=bdjcq2h4bwvlgd8qw1y8q2cljh3xgz9j.ls error="server returned 404: 404 page not found\n"11002026/09/23 13:23:58 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign11012026/09/23 13:23:58 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"11022026/09/23 13:23:58 INFO Signed narinfos id=1 count=111032026/09/23 13:23:58 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign11042026/09/23 13:23:58 INFO Signed narinfos id=2 count=111052026/09/23 13:23:58 INFO Received sign narinfos request method=POST path=/api/pending_closures/3/sign11062026/09/23 13:23:58 INFO Signed narinfos id=3 count=111072026/09/23 13:23:58 INFO Uploading 3 narinfos11082026/09/23 13:23:58 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11092026/09/23 13:23:58 INFO Signed narinfos id=1 count=11110--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (1.18s)1111=== CONT TestPush_RejectsBadRequests11122026/09/23 13:23:58 WARN Failed to register uploaded object key=s8cgxzj2cy8hra1sza0wahlalhhm065g.narinfo error="server returned 404: 404 page not found\n"11132026/09/23 13:23:58 WARN Failed to register uploaded object key=h471z10c0fz3955669wlmja8mn82bc3z.narinfo error="server returned 404: 404 page not found\n"11142026/09/23 13:23:58 INFO Received complete upload request method=POST path=/api/pending_closures/3/complete11152026/09/23 13:23:58 WARN Failed to register uploaded object key=bdjcq2h4bwvlgd8qw1y8q2cljh3xgz9j.narinfo error="server returned 404: 404 page not found\n"11162026/09/23 13:23:58 INFO Completed upload id=311172026/09/23 13:23:58 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete11182026/09/23 13:23:58 INFO Completed upload id=111192026/09/23 13:23:58 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete11202026/09/23 13:23:58 INFO Completed upload id=211212026/09/23 13:23:58 INFO Upload complete. (141ms)1122=== NAME TestClientMultipleUploads1123 client_integration_test.go:369: Uploaded 3 paths in 171.456416ms11242026/09/23 13:23:58 OK 20241026095416_initial_model.sql (135.52ms)11252026/09/23 13:23:58 OK 20251210153512_drop_unused_gin_index.sql (12.47ms)1126--- PASS: TestClientMultipleUploads (1.73s)1127=== CONT TestProxyHeadersOnlyTrustedOnSocket11282026/09/23 13:23:58 OK 20251218171726_add_pins.sql (7.55ms)11292026/09/23 13:23:58 OK 20260628120000_add_object_size_and_stats.sql (21.16ms)11302026/09/23 13:23:58 OK 20260905000000_add_claims.sql (22.14ms)11312026/09/23 13:23:58 OK 20260920000000_drop_claims.sql (13.05ms)11322026/09/23 13:23:58 OK 20260923120000_add_pushes.sql (15.11ms)11332026/09/23 13:23:58 goose: successfully migrated database to version: 2026092312000011342026/09/23 13:23:58 OK 1_commit_pending_closure.sql (1.4ms)11352026/09/23 13:23:58 OK 2_object_stats_trigger.sql (302.75µs)11362026/09/23 13:23:58 OK 3_commit_push.sql (260.63µs)11372026/09/23 13:23:58 goose: up to current file version: 311382026-09-23 13:23:58.320 UTC [62321] ERROR: relation "goose_db_version" does not exist at character 3611392026-09-23 13:23:58.320 UTC [62321] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11402026/09/23 13:23:58 OK 20241026095416_initial_model.sql (50.76ms)11412026/09/23 13:23:58 OK 20251210153512_drop_unused_gin_index.sql (5.42ms)11422026/09/23 13:23:58 OK 20251218171726_add_pins.sql (17.48ms)11432026-09-23 13:23:58.432 UTC [62325] ERROR: relation "goose_db_version" does not exist at character 3611442026-09-23 13:23:58.432 UTC [62325] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11452026/09/23 13:23:58 OK 20260628120000_add_object_size_and_stats.sql (5.33ms)11462026/09/23 13:23:58 OK 20260905000000_add_claims.sql (18.7ms)11472026/09/23 13:23:58 OK 20260920000000_drop_claims.sql (7.45ms)11482026/09/23 13:23:58 OK 20260923120000_add_pushes.sql (6.32ms)11492026/09/23 13:23:58 goose: successfully migrated database to version: 2026092312000011502026/09/23 13:23:58 OK 1_commit_pending_closure.sql (1.05ms)11512026/09/23 13:23:58 OK 2_object_stats_trigger.sql (224.75µs)11522026/09/23 13:23:58 OK 3_commit_push.sql (181.21µs)11532026/09/23 13:23:58 goose: up to current file version: 311542026/09/23 13:23:58 OK 20241026095416_initial_model.sql (72.48ms)11552026/09/23 13:23:58 OK 20251210153512_drop_unused_gin_index.sql (6.57ms)11562026/09/23 13:23:58 OK 20251218171726_add_pins.sql (11.51ms)11572026/09/23 13:23:58 OK 20260628120000_add_object_size_and_stats.sql (21.19ms)1158=== NAME TestClientWithDependencies1159 client_integration_test.go:613: Built derivation: /nix/var/nix/builds/nix-62151-941598581/TestClientWithDependencies1691132436/001/store/n0wbifwl396ljbkdr5s6xjd4gj2kfwb3-test-script11602026/09/23 13:23:58 OK 20260905000000_add_claims.sql (17.83ms)11612026/09/23 13:23:58 OK 20260920000000_drop_claims.sql (4.53ms)11622026/09/23 13:23:58 OK 20260923120000_add_pushes.sql (7.89ms)11632026/09/23 13:23:58 goose: successfully migrated database to version: 2026092312000011642026/09/23 13:23:58 OK 1_commit_pending_closure.sql (833.67µs)11652026/09/23 13:23:58 OK 2_object_stats_trigger.sql (248.38µs)11662026/09/23 13:23:58 OK 3_commit_push.sql (176.33µs)11672026/09/23 13:23:58 goose: up to current file version: 31168 client_integration_test.go:615: Found 1 dependencies (including self)1169=== NAME TestPinProtectsFromGC1170 client_integration_test.go:731: Pinned store path: /nix/var/nix/builds/nix-62151-941598581/TestPinProtectsFromGC2342819278/001/store/hr8fv3jrsvqc9lbycygivjpy5f8xjlg9-pinned-file.txt1171 client_integration_test.go:732: Unpinned store path: /nix/var/nix/builds/nix-62151-941598581/TestPinProtectsFromGC2342819278/001/store/awwdcqvrk641bzy9i7ggdr0gnnfh23g9-unpinned-file.txt11722026/09/23 13:23:58 INFO Received uploads request method=POST path=/api/pending_closures11732026/09/23 13:23:58 INFO Received uploads request method=POST path=/api/pending_closures11742026/09/23 13:23:58 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)11752026/09/23 13:23:58 INFO Uploading hr8fv3jrsvqc9lbycygivjpy5f8xjlg9-pinned-file.txt (128B)11762026/09/23 13:23:58 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)11772026/09/23 13:23:58 INFO Uploading n0wbifwl396ljbkdr5s6xjd4gj2kfwb3-test-script (136B)11782026/09/23 13:23:58 WARN Failed to register uploaded object key=hr8fv3jrsvqc9lbycygivjpy5f8xjlg9.ls error="server returned 404: 404 page not found\n"11792026/09/23 13:23:58 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign11802026/09/23 13:23:58 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"11812026/09/23 13:23:58 WARN Failed to register uploaded object key=n0wbifwl396ljbkdr5s6xjd4gj2kfwb3.ls error="server returned 404: 404 page not found\n"11822026/09/23 13:23:58 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"11832026/09/23 13:23:58 INFO Signed narinfos id=1 count=111842026/09/23 13:23:58 INFO Uploading 1 narinfos11852026/09/23 13:23:58 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete11862026/09/23 13:23:58 WARN Failed to register uploaded object key=log/n44w7l60p118wkbpcwxncy5j01ci00c3-test-script.drv error="server returned 404: 404 page not found\n"11872026/09/23 13:23:58 WARN Failed to register uploaded object key=hr8fv3jrsvqc9lbycygivjpy5f8xjlg9.narinfo error="server returned 404: 404 page not found\n"11882026/09/23 13:23:58 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign11892026/09/23 13:23:58 INFO Signed narinfos id=1 count=111902026/09/23 13:23:58 INFO Uploading 1 narinfos11912026/09/23 13:23:58 INFO Completed upload id=111922026/09/23 13:23:58 INFO Upload complete. (91ms)11932026/09/23 13:23:58 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete11942026/09/23 13:23:58 WARN Failed to register uploaded object key=n0wbifwl396ljbkdr5s6xjd4gj2kfwb3.narinfo error="server returned 404: 404 page not found\n"11952026/09/23 13:23:58 INFO Completed upload id=111962026/09/23 13:23:58 INFO Upload complete. (100ms)1197=== NAME TestClientWithDependencies1198 client_integration_test.go:617: Skipping nix copy test - isolated store (/nix/var/nix/builds/nix-62151-941598581/TestClientWithDependencies1691132436/001/store) requires matching store prefix11992026/09/23 13:23:58 INFO Received uploads request method=POST path=/api/pending_closures1200--- PASS: TestClientWithDependencies (1.87s)1201=== CONT TestPush_OverlappingRootsStoreOneRowPerKey12022026/09/23 13:23:58 INFO Received uploads request method=POST path=/api/pending_closures12032026/09/23 13:23:58 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)12042026/09/23 13:23:58 INFO Uploading awwdcqvrk641bzy9i7ggdr0gnnfh23g9-unpinned-file.txt (128B)12052026/09/23 13:23:58 WARN Failed to register uploaded object key=awwdcqvrk641bzy9i7ggdr0gnnfh23g9.ls error="server returned 404: 404 page not found\n"12062026/09/23 13:23:58 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign12072026/09/23 13:23:58 INFO Signed narinfos id=2 count=112082026/09/23 13:23:58 INFO Uploading 1 narinfos12092026/09/23 13:23:58 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"12102026/09/23 13:23:58 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete12112026/09/23 13:23:58 WARN Failed to register uploaded object key=awwdcqvrk641bzy9i7ggdr0gnnfh23g9.narinfo error="server returned 404: 404 page not found\n"12122026/09/23 13:23:58 INFO Completed upload id=212132026/09/23 13:23:58 INFO Upload complete. (77ms)12142026/09/23 13:23:58 INFO Received uploads request method=POST path=/api/pending_closures12152026/09/23 13:23:58 INFO Received create pin request method=POST path=/api/pins/myapp12162026/09/23 13:23:58 INFO Created/updated pin name=myapp store_path=/nix/var/nix/builds/nix-62151-941598581/TestPinProtectsFromGC2342819278/001/store/hr8fv3jrsvqc9lbycygivjpy5f8xjlg9-pinned-file.txt narinfo_key=hr8fv3jrsvqc9lbycygivjpy5f8xjlg9.narinfo12172026/09/23 13:23:58 INFO Starting cleanup of old closures method=DELETE path=/api/closures12182026/09/23 13:23:58 INFO Garbage collection started12192026/09/23 13:23:58 INFO Aborted multipart uploads count=012202026/09/23 13:23:58 WARN Force mode enabled - objects will be deleted immediately without grace period12212026/09/23 13:23:58 INFO Received uploads request method=POST path=/api/pending_closures12222026/09/23 13:23:58 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)12232026/09/23 13:23:58 INFO Uploading rs69ajjr5kmrwha9wlris2n1zj9h6b6h-shared-dep (136B)12242026/09/23 13:23:58 WARN Failed to register uploaded object key=rs69ajjr5kmrwha9wlris2n1zj9h6b6h.ls error="server returned 404: 404 page not found\n"12252026/09/23 13:23:58 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign12262026/09/23 13:23:58 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"12272026/09/23 13:23:58 INFO Signed narinfos id=2 count=112282026/09/23 13:23:58 INFO Uploading 1 narinfos12292026/09/23 13:23:58 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete12302026/09/23 13:23:58 WARN Failed to register uploaded object key=rs69ajjr5kmrwha9wlris2n1zj9h6b6h.narinfo error="server returned 404: 404 page not found\n"12312026/09/23 13:23:59 INFO Completed upload id=212322026/09/23 13:23:59 INFO Upload complete. (106ms)12332026/09/23 13:23:59 INFO Received uploads request method=POST path=/api/pending_closures12342026/09/23 13:23:59 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)12352026/09/23 13:23:59 INFO Uploading w865mppvvql81hqhfv9jmdbamdyyi2lh-top (256B)12362026/09/23 13:23:59 INFO Uploading rs69ajjr5kmrwha9wlris2n1zj9h6b6h-shared-dep (136B)12372026/09/23 13:23:59 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12382026/09/23 13:23:59 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=YjI3YWFhNzYtOTcxMi00OTgzLWIwMmMtMjMwNjlmNGUzMmZiLmQxNTUzNjcyLWM4ZmYtNGQxYy1iOTFhLTU3ZDg5N2Y5MTRkY3gxNzkwMTY5ODM4Nzk2MDQ4MDAw12392026/09/23 13:23:59 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=YjI3YWFhNzYtOTcxMi00OTgzLWIwMmMtMjMwNjlmNGUzMmZiLmQxNTUzNjcyLWM4ZmYtNGQxYy1iOTFhLTU3ZDg5N2Y5MTRkY3gxNzkwMTY5ODM4Nzk2MDQ4MDAw parts=11240--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (1.89s)1241=== CONT TestReadRedirectUsesPublicS3URL12422026/09/23 13:23:59 WARN Failed to register uploaded object key=w865mppvvql81hqhfv9jmdbamdyyi2lh.ls error="server returned 404: 404 page not found\n"12432026/09/23 13:23:59 WARN Failed to register uploaded object key=nar/1fzj01x43c5ibgax8k99kqm4r7fkkkfwi0gwg7xnpizsxlvabsw6.nar.zst error="server returned 404: 404 page not found\n"12442026-09-23 13:23:59.035 UTC [62363] ERROR: relation "goose_db_version" does not exist at character 3612452026-09-23 13:23:59.035 UTC [62363] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12462026/09/23 13:23:59 INFO Received uploads request method=POST path=/api/pending_closures12472026/09/23 13:23:59 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"12482026/09/23 13:23:59 INFO Received sign narinfos request method=POST path=/api/pending_closures/3/sign12492026/09/23 13:23:59 WARN Failed to register uploaded object key=rs69ajjr5kmrwha9wlris2n1zj9h6b6h.ls error="server returned 404: 404 page not found\n"12502026/09/23 13:23:59 INFO Signed narinfos id=3 count=112512026/09/23 13:23:59 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign12522026/09/23 13:23:59 INFO Signed narinfos id=1 count=112532026/09/23 13:23:59 INFO Uploading 2 narinfos12542026/09/23 13:23:59 WARN Failed to register uploaded object key=w865mppvvql81hqhfv9jmdbamdyyi2lh.narinfo error="server returned 404: 404 page not found\n"12552026/09/23 13:23:59 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete12562026/09/23 13:23:59 WARN Failed to register uploaded object key=rs69ajjr5kmrwha9wlris2n1zj9h6b6h.narinfo error="server returned 404: 404 page not found\n"12572026/09/23 13:23:59 INFO Completed upload id=112582026/09/23 13:23:59 INFO Received complete upload request method=POST path=/api/pending_closures/3/complete12592026/09/23 13:23:59 INFO Completed upload id=312602026/09/23 13:23:59 INFO Upload complete. (256ms)1261=== NAME TestClientSharedPathCommittedMidPush1262 client_integration_test.go:680: Retrieved narinfo from S3:1263 StorePath: /nix/var/nix/builds/nix-62151-941598581/TestClientSharedPathCommittedMidPush1959652371/001/store/rs69ajjr5kmrwha9wlris2n1zj9h6b6h-shared-dep1264 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1265 Compression: zstd1266 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821267 NarSize: 1361268 References: 1269 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1270 client_integration_test.go:680: Retrieved narinfo from S3:1271 StorePath: /nix/var/nix/builds/nix-62151-941598581/TestClientSharedPathCommittedMidPush1959652371/001/store/w865mppvvql81hqhfv9jmdbamdyyi2lh-top1272 URL: nar/1fzj01x43c5ibgax8k99kqm4r7fkkkfwi0gwg7xnpizsxlvabsw6.nar.zst1273 Compression: zstd1274 NarHash: sha256:1fzj01x43c5ibgax8k99kqm4r7fkkkfwi0gwg7xnpizsxlvabsw61275 NarSize: 2561276 References: /nix/var/nix/builds/nix-62151-941598581/TestClientSharedPathCommittedMidPush1959652371/001/store/rs69ajjr5kmrwha9wlris2n1zj9h6b6h-shared-dep1277 CA: text:sha256:1nvcvanydsy1rlxa2148mxjdwf0skzp8pms71p757kgcrhwli7yj12782026/09/23 13:23:59 INFO Received uploads request method=POST path=/api/pending_closures1279--- PASS: TestClientSharedPathCommittedMidPush (2.25s)1280=== CONT TestReadProxyRangeRequest12812026-09-23 13:23:59.135 UTC [62368] ERROR: relation "goose_db_version" does not exist at character 3612822026-09-23 13:23:59.135 UTC [62368] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12832026/09/23 13:23:59 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=012842026/09/23 13:23:59 INFO Vacuumed table table=pending_closures12852026/09/23 13:23:59 INFO Vacuumed table table=pending_objects12862026/09/23 13:23:59 INFO Vacuumed table table=multipart_uploads12872026/09/23 13:23:59 INFO Vacuumed table table=closures12882026/09/23 13:23:59 OK 20241026095416_initial_model.sql (185.44ms)12892026/09/23 13:23:59 INFO Vacuumed table table=objects12902026/09/23 13:23:59 OK 20251210153512_drop_unused_gin_index.sql (7.85ms)12912026/09/23 13:23:59 OK 20251218171726_add_pins.sql (23.25ms)12922026/09/23 13:23:59 OK 20260628120000_add_object_size_and_stats.sql (33.03ms)12932026/09/23 13:23:59 OK 20241026095416_initial_model.sql (160.06ms)12942026/09/23 13:23:59 OK 20251210153512_drop_unused_gin_index.sql (6.92ms)12952026/09/23 13:23:59 OK 20251218171726_add_pins.sql (16.3ms)12962026/09/23 13:23:59 OK 20260905000000_add_claims.sql (45.13ms)12972026/09/23 13:23:59 OK 20260628120000_add_object_size_and_stats.sql (36.71ms)12982026/09/23 13:23:59 OK 20260920000000_drop_claims.sql (43.56ms)12992026/09/23 13:23:59 OK 20260923120000_add_pushes.sql (10.27ms)13002026/09/23 13:23:59 goose: successfully migrated database to version: 2026092312000013012026/09/23 13:23:59 OK 1_commit_pending_closure.sql (1.12ms)13022026/09/23 13:23:59 OK 2_object_stats_trigger.sql (263.33µs)13032026/09/23 13:23:59 OK 3_commit_push.sql (219.33µs)13042026/09/23 13:23:59 goose: up to current file version: 313052026/09/23 13:23:59 OK 20260905000000_add_claims.sql (34.42ms)13062026/09/23 13:23:59 OK 20260920000000_drop_claims.sql (16.3ms)13072026/09/23 13:23:59 OK 20260923120000_add_pushes.sql (8.6ms)13082026/09/23 13:23:59 goose: successfully migrated database to version: 2026092312000013092026/09/23 13:23:59 OK 1_commit_pending_closure.sql (1.1ms)13102026/09/23 13:23:59 OK 2_object_stats_trigger.sql (265µs)13112026/09/23 13:23:59 OK 3_commit_push.sql (221.04µs)13122026/09/23 13:23:59 goose: up to current file version: 31313=== NAME TestClientIntegration1314 client_integration_test.go:286: Created store path: /nix/var/nix/builds/nix-62151-941598581/TestClientIntegration1862947878/002/store/jaxjvrakh9935z7f81qqnyr2dy8b8yqz-test-file.txt13152026/09/23 13:23:59 INFO Received uploads request method=POST path=/api/pending_closures13162026/09/23 13:23:59 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)13172026/09/23 13:23:59 INFO Uploading jaxjvrakh9935z7f81qqnyr2dy8b8yqz-test-file.txt (152B)13182026/09/23 13:23:59 WARN Failed to register uploaded object key=jaxjvrakh9935z7f81qqnyr2dy8b8yqz.ls error="server returned 404: 404 page not found\n"13192026/09/23 13:23:59 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign13202026/09/23 13:23:59 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"13212026/09/23 13:23:59 INFO Signed narinfos id=1 count=113222026/09/23 13:23:59 INFO Uploading 1 narinfos13232026/09/23 13:23:59 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete13242026/09/23 13:23:59 WARN Failed to register uploaded object key=jaxjvrakh9935z7f81qqnyr2dy8b8yqz.narinfo error="server returned 404: 404 page not found\n"13252026/09/23 13:23:59 INFO Completed upload id=113262026/09/23 13:23:59 INFO Upload complete. (130ms)13272026/09/23 13:23:59 INFO All 1 paths already cached1328 client_integration_test.go:312: Retrieved narinfo from S3:1329 StorePath: /nix/var/nix/builds/nix-62151-941598581/TestClientIntegration1862947878/002/store/jaxjvrakh9935z7f81qqnyr2dy8b8yqz-test-file.txt1330 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1331 Compression: zstd1332 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11333 NarSize: 1521334 References: 1335 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11336 client_integration_test.go:313: Retrieved .ls file from S3 (compressed size: 77 bytes)1337 client_integration_test.go:313: Decompressed .ls content (64 bytes):1338 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1339 client_integration_test.go:316: Testing garbage collection...13402026/09/23 13:23:59 INFO Starting cleanup of old closures method=DELETE path=/api/closures13412026/09/23 13:23:59 INFO Garbage collection started13422026/09/23 13:23:59 INFO Aborted multipart uploads count=013432026/09/23 13:23:59 WARN Force mode enabled - objects will be deleted immediately without grace period1344=== RUN TestPush_RejectsBadRequests/bad_root1345=== PAUSE TestPush_RejectsBadRequests/bad_root1346=== RUN TestPush_RejectsBadRequests/root_not_in_objects1347=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects1348=== RUN TestPush_RejectsBadRequests/no_roots1349=== PAUSE TestPush_RejectsBadRequests/no_roots1350=== RUN TestPush_RejectsBadRequests/no_objects1351=== PAUSE TestPush_RejectsBadRequests/no_objects1352=== CONT TestReadRedirectKeepsNarinfoProxied13532026/09/23 13:23:59 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=013542026/09/23 13:23:59 INFO Starting HTTP server address=127.0.0.1:5849313552026/09/23 13:23:59 INFO Starting HTTP server address=/nix/var/nix/builds/nix-62151-941598581/TestProxyHeadersOnlyTrustedOnSocket1073526406/001/proxy.sock13562026/09/23 13:23:59 INFO Vacuumed table table=pending_closures13572026/09/23 13:23:59 WARN mTLS auth: subject not in bound subjects subject="CN=someone"13582026/09/23 13:23:59 INFO Shutdown signal received, draining in-flight requests timeout=10s1359=== NAME TestClientCADerivations1360 client_ca_test.go:136: Built CA derivation: /nix/var/nix/builds/nix-62151-941598581/TestClientCADerivations659885082/001/store/6jya39h9kgzf5rk55r8mdq22r20zr018-ca-test1361--- PASS: TestProxyHeadersOnlyTrustedOnSocket (1.75s)1362=== CONT TestReadRedirectNar13632026/09/23 13:23:59 INFO Vacuumed table table=pending_objects13642026/09/23 13:23:59 INFO Vacuumed table table=multipart_uploads13652026/09/23 13:24:00 INFO Vacuumed table table=closures1366=== NAME TestClientCADerivations1367 client_ca_test.go:139: Found 1 dependencies (including self)13682026/09/23 13:24:00 INFO Vacuumed table table=objects13692026-09-23 13:24:00.043 UTC [62396] ERROR: relation "goose_db_version" does not exist at character 3613702026-09-23 13:24:00.043 UTC [62396] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13712026/09/23 13:24:00 OK 20241026095416_initial_model.sql (23.34ms)13722026/09/23 13:24:00 OK 20251210153512_drop_unused_gin_index.sql (532.88µs)13732026/09/23 13:24:00 OK 20251218171726_add_pins.sql (834.33µs)13742026-09-23 13:24:00.100 UTC [62402] ERROR: relation "goose_db_version" does not exist at character 3613752026-09-23 13:24:00.100 UTC [62402] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13762026/09/23 13:24:00 OK 20260628120000_add_object_size_and_stats.sql (17.39ms)13772026/09/23 13:24:00 OK 20260905000000_add_claims.sql (18.19ms)13782026/09/23 13:24:00 OK 20260920000000_drop_claims.sql (7.3ms)13792026/09/23 13:24:00 INFO Received uploads request method=POST path=/api/pending_closures13802026/09/23 13:24:00 OK 20260923120000_add_pushes.sql (5.92ms)13812026/09/23 13:24:00 goose: successfully migrated database to version: 2026092312000013822026/09/23 13:24:00 OK 1_commit_pending_closure.sql (1.04ms)13832026/09/23 13:24:00 WARN Rate limiter enabled after throttle name=s3-test rate=513842026/09/23 13:24:00 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."1385=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle1386 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=101387 throttle_test.go:215: Rate limiter: enabled=true, rate=5.0013882026/09/23 13:24:00 OK 2_object_stats_trigger.sql (412.75µs)1389--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (5.18s)1390=== CONT TestReadProxyDisabled13912026/09/23 13:24:00 OK 3_commit_push.sql (367.25µs)13922026/09/23 13:24:00 goose: up to current file version: 313932026/09/23 13:24:00 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)13942026/09/23 13:24:00 INFO Uploading 6jya39h9kgzf5rk55r8mdq22r20zr018-ca-test (144B)13952026/09/23 13:24:00 WARN Failed to register uploaded object key=6jya39h9kgzf5rk55r8mdq22r20zr018.ls error="server returned 404: 404 page not found\n"13962026/09/23 13:24:00 WARN Failed to register uploaded object key=log/siqc6sfrnsxggnpi3c6fk96192q9fjwv-ca-test.drv error="server returned 404: 404 page not found\n"13972026/09/23 13:24:00 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"13982026/09/23 13:24:00 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign13992026/09/23 13:24:00 INFO Signed narinfos id=1 count=114002026/09/23 13:24:00 INFO Uploading 1 narinfos14012026/09/23 13:24:00 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete14022026/09/23 13:24:00 WARN Failed to register uploaded object key=6jya39h9kgzf5rk55r8mdq22r20zr018.narinfo error="server returned 404: 404 page not found\n"14032026/09/23 13:24:00 INFO Completed upload id=114042026/09/23 13:24:00 INFO Upload complete. (143ms)1405=== NAME TestClientCADerivations1406 client_ca_test.go:180: Narinfo contains CA field: StorePath: /nix/var/nix/builds/nix-62151-941598581/TestClientCADerivations659885082/001/store/6jya39h9kgzf5rk55r8mdq22r20zr018-ca-test1407 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1408 Compression: zstd1409 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1410 NarSize: 1441411 References: 1412 Deriver: /nix/var/nix/builds/nix-62151-941598581/TestClientCADerivations659885082/001/store/siqc6sfrnsxggnpi3c6fk96192q9fjwv-ca-test.drv1413 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1414 client_ca_test.go:185: Checking for realisation files in S3...1415 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1416 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache14172026/09/23 13:24:00 OK 20241026095416_initial_model.sql (104.88ms)14182026/09/23 13:24:00 OK 20251210153512_drop_unused_gin_index.sql (11.36ms)14192026/09/23 13:24:00 INFO Received complete multipart upload request method=POST path=/api/multipart/complete14202026/09/23 13:24:00 OK 20251218171726_add_pins.sql (17.21ms)1421 client_ca_test.go:258: nix copy output: error: binary cache 's3://bucket24?endpoint=http://localhost:58390®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/nix/var/nix/builds/nix-62151-941598581/TestClientCADerivations659885082/001/store'1422 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 114232026/09/23 13:24:00 OK 20260628120000_add_object_size_and_stats.sql (81.02ms)14242026/09/23 13:24:00 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=YjI3YWFhNzYtOTcxMi00OTgzLWIwMmMtMjMwNjlmNGUzMmZiLmQ4YmQ0NzM1LWJhODktNGZjMC1iMDY0LTFmMjgzMmM4MzdjY3gxNzkwMTY5ODM5MDU3MjQzMDAw parts=121425--- PASS: TestRedundantMultipartUpload (3.09s)1426=== CONT TestReadProxyRootRedirectsToIndexHTML14272026-09-23 13:24:00.376 UTC [62409] ERROR: relation "goose_db_version" does not exist at character 3614282026-09-23 13:24:00.376 UTC [62409] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1429--- PASS: TestClientCADerivations (2.73s)1430=== CONT TestReadProxyConditionalGet14312026/09/23 13:24:00 INFO Received push request method=POST path=/api/pushes14322026/09/23 13:24:00 OK 20260905000000_add_claims.sql (41.88ms)14332026/09/23 13:24:00 OK 20260920000000_drop_claims.sql (7.35ms)14342026/09/23 13:24:00 OK 20260923120000_add_pushes.sql (7.99ms)14352026/09/23 13:24:00 goose: successfully migrated database to version: 2026092312000014362026/09/23 13:24:00 OK 1_commit_pending_closure.sql (1.49ms)14372026/09/23 13:24:00 OK 2_object_stats_trigger.sql (255.46µs)14382026/09/23 13:24:00 OK 3_commit_push.sql (222.63µs)14392026/09/23 13:24:00 goose: up to current file version: 31440--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (1.67s)1441=== CONT TestReadProxyHead14422026/09/23 13:24:00 OK 20241026095416_initial_model.sql (83.85ms)14432026/09/23 13:24:00 OK 20251210153512_drop_unused_gin_index.sql (1.21ms)14442026/09/23 13:24:00 OK 20251218171726_add_pins.sql (12.21ms)14452026/09/23 13:24:00 OK 20260628120000_add_object_size_and_stats.sql (11.33ms)14462026/09/23 13:24:00 OK 20260905000000_add_claims.sql (26.91ms)14472026/09/23 13:24:00 OK 20260920000000_drop_claims.sql (13.94ms)14482026/09/23 13:24:00 OK 20260923120000_add_pushes.sql (4.69ms)14492026/09/23 13:24:00 goose: successfully migrated database to version: 2026092312000014502026/09/23 13:24:00 OK 1_commit_pending_closure.sql (1.3ms)14512026/09/23 13:24:00 OK 2_object_stats_trigger.sql (315.71µs)14522026/09/23 13:24:00 OK 3_commit_push.sql (278.92µs)14532026/09/23 13:24:00 goose: up to current file version: 31454--- PASS: TestReadRedirectUsesPublicS3URL (1.56s)1455=== CONT TestReadProxyInvalidPath1456--- PASS: TestReadProxyRangeRequest (1.63s)1457=== CONT TestReadProxy40414582026-09-23 13:24:00.781 UTC [62419] ERROR: relation "goose_db_version" does not exist at character 3614592026-09-23 13:24:00.781 UTC [62419] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14602026-09-23 13:24:00.811 UTC [62421] ERROR: relation "goose_db_version" does not exist at character 3614612026-09-23 13:24:00.811 UTC [62421] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14622026/09/23 13:24:00 OK 20241026095416_initial_model.sql (17.5ms)14632026/09/23 13:24:00 OK 20251210153512_drop_unused_gin_index.sql (887.25µs)14642026/09/23 13:24:00 OK 20251218171726_add_pins.sql (2.03ms)14652026/09/23 13:24:00 OK 20260628120000_add_object_size_and_stats.sql (7.67ms)14662026/09/23 13:24:00 OK 20260905000000_add_claims.sql (1.47ms)14672026/09/23 13:24:00 OK 20260920000000_drop_claims.sql (811.42µs)14682026/09/23 13:24:00 OK 20260923120000_add_pushes.sql (498.17µs)14692026/09/23 13:24:00 goose: successfully migrated database to version: 2026092312000014702026/09/23 13:24:00 OK 1_commit_pending_closure.sql (1.41ms)14712026/09/23 13:24:00 OK 2_object_stats_trigger.sql (617.96µs)14722026/09/23 13:24:00 OK 3_commit_push.sql (340µs)14732026/09/23 13:24:00 goose: up to current file version: 314742026/09/23 13:24:00 OK 20241026095416_initial_model.sql (12.27ms)14752026/09/23 13:24:00 OK 20251210153512_drop_unused_gin_index.sql (448.33µs)14762026/09/23 13:24:00 OK 20251218171726_add_pins.sql (895.96µs)14772026/09/23 13:24:00 OK 20260628120000_add_object_size_and_stats.sql (19.55ms)14782026/09/23 13:24:00 OK 20260905000000_add_claims.sql (25.69ms)14792026/09/23 13:24:00 OK 20260920000000_drop_claims.sql (26.01ms)14802026/09/23 13:24:00 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=01481=== NAME TestPinProtectsFromGC1482 client_integration_test.go:794: Pin successfully protected closure from garbage collection14832026/09/23 13:24:00 OK 20260923120000_add_pushes.sql (9.42ms)14842026/09/23 13:24:00 goose: successfully migrated database to version: 2026092312000014852026/09/23 13:24:00 OK 1_commit_pending_closure.sql (1.34ms)14862026/09/23 13:24:00 OK 2_object_stats_trigger.sql (298.79µs)14872026/09/23 13:24:00 OK 3_commit_push.sql (245.63µs)14882026/09/23 13:24:00 goose: up to current file version: 31489--- PASS: TestPinProtectsFromGC (4.18s)1490=== CONT TestReadProxyNarStreaming1491--- PASS: TestReadRedirectKeepsNarinfoProxied (1.29s)1492=== CONT TestReadProxyNarinfoAlreadyDecompressed1493--- PASS: TestReadRedirectNar (1.33s)1494=== CONT TestReadProxyNarinfo14952026-09-23 13:24:01.547 UTC [62428] ERROR: relation "goose_db_version" does not exist at character 3614962026-09-23 13:24:01.547 UTC [62428] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14972026-09-23 13:24:01.656 UTC [62429] ERROR: relation "goose_db_version" does not exist at character 3614982026-09-23 13:24:01.656 UTC [62429] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14992026-09-23 13:24:01.656 UTC [62430] ERROR: relation "goose_db_version" does not exist at character 3615002026-09-23 13:24:01.656 UTC [62430] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15012026-09-23 13:24:01.656 UTC [62431] ERROR: relation "goose_db_version" does not exist at character 3615022026-09-23 13:24:01.656 UTC [62431] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15032026/09/23 13:24:01 OK 20241026095416_initial_model.sql (86.23ms)15042026/09/23 13:24:01 OK 20251210153512_drop_unused_gin_index.sql (6.14ms)15052026/09/23 13:24:01 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=015062026/09/23 13:24:01 OK 20251218171726_add_pins.sql (17.41ms)1507=== NAME TestClientIntegration1508 client_integration_test.go:323: Objects in database after GC:1509 client_integration_test.go:323: Successfully deleted all objects with GC --force1510--- PASS: TestClientIntegration (4.35s)1511=== CONT TestIsValidCachePath1512=== RUN TestIsValidCachePath/narinfo1513=== PAUSE TestIsValidCachePath/narinfo1514=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars1515=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars1516=== RUN TestIsValidCachePath/nar_zst1517=== PAUSE TestIsValidCachePath/nar_zst15182026/09/23 13:24:01 OK 20260628120000_add_object_size_and_stats.sql (35.47ms)1519=== RUN TestIsValidCachePath/nar_xz1520=== PAUSE TestIsValidCachePath/nar_xz1521=== RUN TestIsValidCachePath/nar_bz21522=== PAUSE TestIsValidCachePath/nar_bz21523=== RUN TestIsValidCachePath/nar_uncompressed1524=== PAUSE TestIsValidCachePath/nar_uncompressed1525=== RUN TestIsValidCachePath/ls1526=== PAUSE TestIsValidCachePath/ls1527=== RUN TestIsValidCachePath/log1528=== PAUSE TestIsValidCachePath/log1529=== RUN TestIsValidCachePath/realisation1530=== PAUSE TestIsValidCachePath/realisation1531=== RUN TestIsValidCachePath/nix-cache-info1532=== PAUSE TestIsValidCachePath/nix-cache-info1533=== RUN TestIsValidCachePath/index.html1534=== PAUSE TestIsValidCachePath/index.html1535=== RUN TestIsValidCachePath/traversal_parent1536=== PAUSE TestIsValidCachePath/traversal_parent1537=== RUN TestIsValidCachePath/traversal_in_middle1538=== PAUSE TestIsValidCachePath/traversal_in_middle1539=== RUN TestIsValidCachePath/invalid_char_e1540=== PAUSE TestIsValidCachePath/invalid_char_e1541=== RUN TestIsValidCachePath/invalid_char_u1542=== PAUSE TestIsValidCachePath/invalid_char_u1543=== RUN TestIsValidCachePath/random_path1544=== PAUSE TestIsValidCachePath/random_path1545=== RUN TestIsValidCachePath/empty1546=== PAUSE TestIsValidCachePath/empty1547=== RUN TestIsValidCachePath/leading_slash1548=== PAUSE TestIsValidCachePath/leading_slash1549=== RUN TestIsValidCachePath/wrong_extension1550=== PAUSE TestIsValidCachePath/wrong_extension1551=== RUN TestIsValidCachePath/short_hash1552=== PAUSE TestIsValidCachePath/short_hash1553=== CONT TestPush_CommitFailsWhenSkippedKeyWasCollected15542026/09/23 13:24:01 OK 20241026095416_initial_model.sql (78.58ms)15552026/09/23 13:24:01 OK 20241026095416_initial_model.sql (80.82ms)15562026/09/23 13:24:01 OK 20251210153512_drop_unused_gin_index.sql (8.28ms)15572026/09/23 13:24:01 OK 20251210153512_drop_unused_gin_index.sql (7.63ms)15582026/09/23 13:24:01 OK 20260905000000_add_claims.sql (34.73ms)15592026/09/23 13:24:01 OK 20241026095416_initial_model.sql (93.63ms)15602026/09/23 13:24:01 OK 20251218171726_add_pins.sql (9.07ms)15612026/09/23 13:24:01 OK 20251210153512_drop_unused_gin_index.sql (1.76ms)15622026/09/23 13:24:01 OK 20251218171726_add_pins.sql (8.74ms)15632026/09/23 13:24:01 OK 20260920000000_drop_claims.sql (3.43ms)15642026/09/23 13:24:01 OK 20251218171726_add_pins.sql (2.49ms)15652026/09/23 13:24:01 OK 20260923120000_add_pushes.sql (3.2ms)15662026/09/23 13:24:01 goose: successfully migrated database to version: 2026092312000015672026/09/23 13:24:01 OK 20260628120000_add_object_size_and_stats.sql (6.05ms)15682026/09/23 13:24:01 OK 20260628120000_add_object_size_and_stats.sql (6.34ms)15692026/09/23 13:24:01 OK 1_commit_pending_closure.sql (2.92ms)15702026/09/23 13:24:01 OK 20260628120000_add_object_size_and_stats.sql (4.92ms)15712026-09-23 13:24:01.803 UTC [62434] ERROR: relation "goose_db_version" does not exist at character 3615722026-09-23 13:24:01.803 UTC [62434] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15732026/09/23 13:24:01 OK 2_object_stats_trigger.sql (995.29µs)15742026/09/23 13:24:01 OK 3_commit_push.sql (361.75µs)15752026/09/23 13:24:01 goose: up to current file version: 315762026/09/23 13:24:01 OK 20260905000000_add_claims.sql (3.86ms)15772026/09/23 13:24:01 OK 20260905000000_add_claims.sql (2.8ms)15782026/09/23 13:24:01 OK 20260905000000_add_claims.sql (3.35ms)15792026/09/23 13:24:01 OK 20260920000000_drop_claims.sql (1.51ms)15802026/09/23 13:24:01 OK 20260920000000_drop_claims.sql (1.4ms)15812026/09/23 13:24:01 OK 20260923120000_add_pushes.sql (843.54µs)15822026/09/23 13:24:01 goose: successfully migrated database to version: 2026092312000015832026/09/23 13:24:01 OK 20260920000000_drop_claims.sql (1.14ms)15842026/09/23 13:24:01 OK 20260923120000_add_pushes.sql (757.54µs)15852026/09/23 13:24:01 goose: successfully migrated database to version: 2026092312000015862026/09/23 13:24:01 OK 1_commit_pending_closure.sql (1.38ms)15872026/09/23 13:24:01 OK 1_commit_pending_closure.sql (1.31ms)15882026/09/23 13:24:01 OK 2_object_stats_trigger.sql (269.79µs)15892026/09/23 13:24:01 OK 2_object_stats_trigger.sql (272.13µs)15902026/09/23 13:24:01 OK 3_commit_push.sql (234.75µs)15912026/09/23 13:24:01 goose: up to current file version: 315922026/09/23 13:24:01 OK 3_commit_push.sql (258.33µs)15932026/09/23 13:24:01 goose: up to current file version: 315942026/09/23 13:24:01 OK 20260923120000_add_pushes.sql (8.83ms)15952026/09/23 13:24:01 goose: successfully migrated database to version: 2026092312000015962026/09/23 13:24:01 OK 1_commit_pending_closure.sql (1.48ms)15972026/09/23 13:24:01 OK 2_object_stats_trigger.sql (304.17µs)15982026/09/23 13:24:01 OK 3_commit_push.sql (225.54µs)15992026/09/23 13:24:01 goose: up to current file version: 316002026-09-23 13:24:01.911 UTC [62435] ERROR: relation "goose_db_version" does not exist at character 3616012026-09-23 13:24:01.911 UTC [62435] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16022026/09/23 13:24:01 OK 20241026095416_initial_model.sql (99.89ms)16032026/09/23 13:24:01 OK 20251210153512_drop_unused_gin_index.sql (10.94ms)16042026/09/23 13:24:01 OK 20251218171726_add_pins.sql (32.38ms)16052026/09/23 13:24:02 OK 20260628120000_add_object_size_and_stats.sql (38.06ms)1606--- PASS: TestReadProxyDisabled (1.88s)1607=== CONT TestService_cleanupPendingClosuresHandler16082026/09/23 13:24:02 OK 20260905000000_add_claims.sql (94.18ms)16092026/09/23 13:24:02 OK 20260920000000_drop_claims.sql (25.58ms)16102026/09/23 13:24:02 OK 20241026095416_initial_model.sql (192.6ms)16112026/09/23 13:24:02 OK 20251210153512_drop_unused_gin_index.sql (9.93ms)16122026/09/23 13:24:02 OK 20260923120000_add_pushes.sql (20.79ms)16132026/09/23 13:24:02 goose: successfully migrated database to version: 2026092312000016142026/09/23 13:24:02 OK 1_commit_pending_closure.sql (4.27ms)16152026/09/23 13:24:02 OK 2_object_stats_trigger.sql (774.42µs)16162026/09/23 13:24:02 OK 3_commit_push.sql (645.88µs)16172026/09/23 13:24:02 goose: up to current file version: 316182026/09/23 13:24:02 OK 20251218171726_add_pins.sql (23.09ms)16192026/09/23 13:24:02 OK 20260628120000_add_object_size_and_stats.sql (29.8ms)16202026/09/23 13:24:02 OK 20260905000000_add_claims.sql (49.3ms)16212026/09/23 13:24:02 OK 20260920000000_drop_claims.sql (46.33ms)16222026/09/23 13:24:02 OK 20260923120000_add_pushes.sql (12.61ms)16232026/09/23 13:24:02 goose: successfully migrated database to version: 2026092312000016242026/09/23 13:24:02 OK 1_commit_pending_closure.sql (4.22ms)16252026/09/23 13:24:02 OK 2_object_stats_trigger.sql (1.26ms)16262026/09/23 13:24:02 OK 3_commit_push.sql (865µs)16272026/09/23 13:24:02 goose: up to current file version: 31628--- PASS: TestReadProxyHead (1.92s)1629=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT16302026-09-23 13:24:02.625 UTC [62440] ERROR: relation "goose_db_version" does not exist at character 3616312026-09-23 13:24:02.625 UTC [62440] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1632--- PASS: TestReadProxyRootRedirectsToIndexHTML (2.33s)1633=== CONT TestCompleteMultipartUnregistered16342026-09-23 13:24:02.744 UTC [62443] ERROR: relation "goose_db_version" does not exist at character 3616352026-09-23 13:24:02.744 UTC [62443] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16362026-09-23 13:24:02.899 UTC [62444] ERROR: relation "goose_db_version" does not exist at character 3616372026-09-23 13:24:02.899 UTC [62444] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16382026/09/23 13:24:02 OK 20241026095416_initial_model.sql (151.86ms)16392026/09/23 13:24:02 OK 20251210153512_drop_unused_gin_index.sql (8.3ms)16402026/09/23 13:24:02 OK 20251218171726_add_pins.sql (27.66ms)16412026/09/23 13:24:02 OK 20241026095416_initial_model.sql (129.3ms)16422026/09/23 13:24:02 OK 20251210153512_drop_unused_gin_index.sql (15.88ms)1643--- PASS: TestReadProxyConditionalGet (2.60s)1644=== CONT TestService_verifyS3Integrity16452026/09/23 13:24:02 OK 20251218171726_add_pins.sql (24.97ms)16462026/09/23 13:24:02 OK 20260628120000_add_object_size_and_stats.sql (53.48ms)16472026/09/23 13:24:03 OK 20260628120000_add_object_size_and_stats.sql (53.9ms)16482026/09/23 13:24:03 OK 20260905000000_add_claims.sql (69.45ms)16492026/09/23 13:24:03 OK 20260920000000_drop_claims.sql (39.4ms)16502026/09/23 13:24:03 OK 20260905000000_add_claims.sql (62.6ms)16512026/09/23 13:24:03 OK 20260923120000_add_pushes.sql (12.56ms)16522026/09/23 13:24:03 goose: successfully migrated database to version: 2026092312000016532026/09/23 13:24:03 OK 1_commit_pending_closure.sql (5.08ms)16542026/09/23 13:24:03 OK 2_object_stats_trigger.sql (807.71µs)16552026/09/23 13:24:03 OK 3_commit_push.sql (649.25µs)16562026/09/23 13:24:03 goose: up to current file version: 316572026/09/23 13:24:03 OK 20260920000000_drop_claims.sql (40.46ms)16582026/09/23 13:24:03 OK 20241026095416_initial_model.sql (177.84ms)16592026/09/23 13:24:03 OK 20260923120000_add_pushes.sql (13.61ms)16602026/09/23 13:24:03 goose: successfully migrated database to version: 2026092312000016612026/09/23 13:24:03 OK 1_commit_pending_closure.sql (3.97ms)16622026/09/23 13:24:03 OK 2_object_stats_trigger.sql (741µs)16632026/09/23 13:24:03 OK 3_commit_push.sql (633.54µs)16642026/09/23 13:24:03 goose: up to current file version: 316652026/09/23 13:24:03 OK 20251210153512_drop_unused_gin_index.sql (17.22ms)16662026/09/23 13:24:03 OK 20251218171726_add_pins.sql (32.26ms)16672026/09/23 13:24:03 OK 20260628120000_add_object_size_and_stats.sql (32.34ms)1668--- PASS: TestReadProxyInvalidPath (2.71s)1669=== CONT TestService_createPendingClosureHandler16702026/09/23 13:24:03 OK 20260905000000_add_claims.sql (56.85ms)16712026/09/23 13:24:03 OK 20260920000000_drop_claims.sql (63.13ms)16722026/09/23 13:24:03 OK 20260923120000_add_pushes.sql (17.69ms)16732026/09/23 13:24:03 goose: successfully migrated database to version: 2026092312000016742026/09/23 13:24:03 OK 1_commit_pending_closure.sql (3.33ms)16752026/09/23 13:24:03 OK 2_object_stats_trigger.sql (739.29µs)16762026/09/23 13:24:03 OK 3_commit_push.sql (493.29µs)16772026/09/23 13:24:03 goose: up to current file version: 31678--- PASS: TestReadProxy404 (2.84s)1679=== CONT TestUploadHandlersRejectInvalidKeys1680=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1681=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1682=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1683=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1684=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1685=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1686=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1687=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1688=== CONT TestUploadHandlersRejectOversizedBody1689=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure1690=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure1691=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart1692=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart1693=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts1694=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts1695=== CONT TestIsValidUploadKey1696=== RUN TestIsValidUploadKey/narinfo1697=== PAUSE TestIsValidUploadKey/narinfo1698=== RUN TestIsValidUploadKey/nar_zst1699=== PAUSE TestIsValidUploadKey/nar_zst1700=== RUN TestIsValidUploadKey/nar_xz1701=== PAUSE TestIsValidUploadKey/nar_xz1702=== RUN TestIsValidUploadKey/nar_plain1703=== PAUSE TestIsValidUploadKey/nar_plain1704=== RUN TestIsValidUploadKey/listing1705=== PAUSE TestIsValidUploadKey/listing1706=== RUN TestIsValidUploadKey/build_log1707=== PAUSE TestIsValidUploadKey/build_log1708=== RUN TestIsValidUploadKey/build_log_home-manager_file1709=== PAUSE TestIsValidUploadKey/build_log_home-manager_file1710=== RUN TestIsValidUploadKey/build_log_plus_in_name1711=== PAUSE TestIsValidUploadKey/build_log_plus_in_name1712=== RUN TestIsValidUploadKey/build_log_question_mark1713=== PAUSE TestIsValidUploadKey/build_log_question_mark1714=== RUN TestIsValidUploadKey/build_log_equals1715=== PAUSE TestIsValidUploadKey/build_log_equals1716=== RUN TestIsValidUploadKey/realisation1717=== PAUSE TestIsValidUploadKey/realisation1718=== RUN TestIsValidUploadKey/realisation_plus_in_output1719=== PAUSE TestIsValidUploadKey/realisation_plus_in_output1720=== RUN TestIsValidUploadKey/nix-cache-info1721=== PAUSE TestIsValidUploadKey/nix-cache-info1722=== RUN TestIsValidUploadKey/index.html1723=== PAUSE TestIsValidUploadKey/index.html1724=== RUN TestIsValidUploadKey/narinfo_key,_nar_type1725=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type1726=== RUN TestIsValidUploadKey/nar_key,_narinfo_type1727=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type1728=== RUN TestIsValidUploadKey/listing_key,_narinfo_type1729=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type1730=== RUN TestIsValidUploadKey/traversal1731=== PAUSE TestIsValidUploadKey/traversal1732=== RUN TestIsValidUploadKey/traversal_nar1733=== PAUSE TestIsValidUploadKey/traversal_nar1734=== RUN TestIsValidUploadKey/absolute1735=== PAUSE TestIsValidUploadKey/absolute1736=== RUN TestIsValidUploadKey/empty_key1737=== PAUSE TestIsValidUploadKey/empty_key1738=== RUN TestIsValidUploadKey/unknown_type1739=== PAUSE TestIsValidUploadKey/unknown_type1740=== CONT TestLeadEndsOnShutdown17412026-09-23 13:24:03.663 UTC [62449] ERROR: relation "goose_db_version" does not exist at character 3617422026-09-23 13:24:03.663 UTC [62449] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17432026-09-23 13:24:03.858 UTC [62452] ERROR: relation "goose_db_version" does not exist at character 3617442026-09-23 13:24:03.858 UTC [62452] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1745--- PASS: TestReadProxyNarStreaming (2.90s)1746=== CONT TestGCTaskStore_StartNew1747--- PASS: TestGCTaskStore_StartNew (0.00s)1748=== CONT TestGCMetrics17492026/09/23 13:24:03 OK 20241026095416_initial_model.sql (135.64ms)17502026/09/23 13:24:03 OK 20251210153512_drop_unused_gin_index.sql (11.19ms)17512026/09/23 13:24:03 OK 20251218171726_add_pins.sql (46.08ms)17522026/09/23 13:24:03 OK 20260628120000_add_object_size_and_stats.sql (51.7ms)17532026/09/23 13:24:04 OK 20260905000000_add_claims.sql (35.1ms)17542026/09/23 13:24:04 OK 20260920000000_drop_claims.sql (26.07ms)17552026/09/23 13:24:04 OK 20260923120000_add_pushes.sql (21.05ms)17562026/09/23 13:24:04 goose: successfully migrated database to version: 2026092312000017572026/09/23 13:24:04 OK 1_commit_pending_closure.sql (4.71ms)17582026/09/23 13:24:04 OK 2_object_stats_trigger.sql (1.58ms)17592026/09/23 13:24:04 OK 3_commit_push.sql (666.96µs)17602026/09/23 13:24:04 goose: up to current file version: 317612026/09/23 13:24:04 OK 20241026095416_initial_model.sql (161.77ms)17622026/09/23 13:24:04 OK 20251210153512_drop_unused_gin_index.sql (8.28ms)17632026/09/23 13:24:04 OK 20251218171726_add_pins.sql (39.78ms)17642026/09/23 13:24:04 OK 20260628120000_add_object_size_and_stats.sql (29.2ms)1765--- PASS: TestReadProxyNarinfoAlreadyDecompressed (3.16s)1766=== CONT TestGCBugBareHashReferences17672026/09/23 13:24:04 OK 20260905000000_add_claims.sql (73.4ms)17682026/09/23 13:24:04 OK 20260920000000_drop_claims.sql (60.72ms)17692026/09/23 13:24:04 OK 20260923120000_add_pushes.sql (9.87ms)17702026/09/23 13:24:04 goose: successfully migrated database to version: 2026092312000017712026/09/23 13:24:04 OK 1_commit_pending_closure.sql (3.33ms)17722026/09/23 13:24:04 OK 2_object_stats_trigger.sql (703.33µs)17732026/09/23 13:24:04 OK 3_commit_push.sql (494.21µs)17742026/09/23 13:24:04 goose: up to current file version: 317752026-09-23 13:24:04.484 UTC [62457] ERROR: relation "goose_db_version" does not exist at character 3617762026-09-23 13:24:04.484 UTC [62457] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1777--- PASS: TestReadProxyNarinfo (3.21s)1778=== CONT TestServerTLSConfig1779=== RUN TestServerTLSConfig/no_client_CA1780=== PAUSE TestServerTLSConfig/no_client_CA1781=== RUN TestServerTLSConfig/missing_CA_file1782=== PAUSE TestServerTLSConfig/missing_CA_file1783=== RUN TestServerTLSConfig/not_a_PEM_file1784=== PAUSE TestServerTLSConfig/not_a_PEM_file1785=== CONT TestParseSingleRange1786=== RUN TestParseSingleRange/none1787=== PAUSE TestParseSingleRange/none1788=== RUN TestParseSingleRange/unknown_unit1789=== PAUSE TestParseSingleRange/unknown_unit1790=== RUN TestParseSingleRange/multi-range_ignored1791=== PAUSE TestParseSingleRange/multi-range_ignored1792=== RUN TestParseSingleRange/malformed_no_dash1793=== PAUSE TestParseSingleRange/malformed_no_dash1794=== RUN TestParseSingleRange/malformed_both_empty1795=== PAUSE TestParseSingleRange/malformed_both_empty1796=== RUN TestParseSingleRange/malformed_end_before_start1797=== PAUSE TestParseSingleRange/malformed_end_before_start1798=== RUN TestParseSingleRange/closed1799=== PAUSE TestParseSingleRange/closed1800=== RUN TestParseSingleRange/open-ended1801=== PAUSE TestParseSingleRange/open-ended1802=== RUN TestParseSingleRange/end_clamped_to_size1803=== PAUSE TestParseSingleRange/end_clamped_to_size1804=== RUN TestParseSingleRange/suffix1805=== PAUSE TestParseSingleRange/suffix1806=== RUN TestParseSingleRange/suffix_exceeds_size1807=== PAUSE TestParseSingleRange/suffix_exceeds_size1808=== RUN TestParseSingleRange/single_byte1809=== PAUSE TestParseSingleRange/single_byte1810=== RUN TestParseSingleRange/start_past_EOF1811=== PAUSE TestParseSingleRange/start_past_EOF1812=== RUN TestParseSingleRange/start_far_past_EOF1813=== PAUSE TestParseSingleRange/start_far_past_EOF1814=== CONT TestCreatePin_ReservedPins18152026/09/23 13:24:04 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:58549/oidc18162026/09/23 13:24:04 OK 20241026095416_initial_model.sql (145.48ms)18172026/09/23 13:24:04 OK 20251210153512_drop_unused_gin_index.sql (1.56ms)18182026/09/23 13:24:04 OK 20251218171726_add_pins.sql (25.51ms)18192026/09/23 13:24:04 INFO Received push request method=POST path=/api/pushes18202026/09/23 13:24:04 OK 20260628120000_add_object_size_and_stats.sql (26.92ms)18212026-09-23 13:24:04.815 UTC [62460] ERROR: relation "goose_db_version" does not exist at character 3618222026-09-23 13:24:04.815 UTC [62460] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18232026/09/23 13:24:04 INFO Received complete push request method=POST path=/api/pushes/1/complete18242026/09/23 13:24:04 OK 20260905000000_add_claims.sql (81.11ms)18252026/09/23 13:24:04 OK 20260920000000_drop_claims.sql (12.98ms)18262026/09/23 13:24:04 INFO Received push request method=POST path=/api/pushes18272026/09/23 13:24:04 OK 20260923120000_add_pushes.sql (15.73ms)18282026/09/23 13:24:04 goose: successfully migrated database to version: 2026092312000018292026/09/23 13:24:04 OK 1_commit_pending_closure.sql (3.85ms)18302026/09/23 13:24:04 OK 2_object_stats_trigger.sql (659.13µs)18312026/09/23 13:24:04 OK 3_commit_push.sql (389.92µs)18322026/09/23 13:24:04 goose: up to current file version: 318332026/09/23 13:24:04 INFO Received complete push request method=POST path=/api/pushes/2/complete18342026-09-23 13:24:04.904 UTC [62461] ERROR: Push object missing: aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.narinfo18352026-09-23 13:24:04.904 UTC [62461] CONTEXT: PL/pgSQL function commit_push(bigint) line 37 at RAISE18362026-09-23 13:24:04.904 UTC [62461] STATEMENT: -- name: CommitPush :exec1837 SELECT commit_push($1::bigint)1838 1839--- PASS: TestPush_CommitFailsWhenSkippedKeyWasCollected (3.15s)1840=== CONT TestResurrectedObjectNotDeleted18412026-09-23 13:24:04.921 UTC [62463] ERROR: relation "goose_db_version" does not exist at character 3618422026-09-23 13:24:04.921 UTC [62463] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18432026/09/23 13:24:04 OK 20241026095416_initial_model.sql (104.24ms)18442026/09/23 13:24:04 OK 20251210153512_drop_unused_gin_index.sql (13.97ms)18452026/09/23 13:24:04 INFO Received cleanup request method=DELETE path=/api/pending_closures18462026/09/23 13:24:05 OK 20251218171726_add_pins.sql (12.92ms)18472026/09/23 13:24:05 INFO Aborted multipart uploads count=018482026/09/23 13:24:05 INFO Received uploads request method=POST path=/api/pending_closures18492026/09/23 13:24:05 OK 20260628120000_add_object_size_and_stats.sql (39.31ms)18502026/09/23 13:24:05 INFO Received cleanup request method=DELETE path=/api/pending_closures18512026/09/23 13:24:05 OK 20241026095416_initial_model.sql (110.89ms)18522026/09/23 13:24:05 OK 20260905000000_add_claims.sql (23.29ms)18532026/09/23 13:24:05 OK 20251210153512_drop_unused_gin_index.sql (6.95ms)18542026/09/23 13:24:05 INFO Aborted multipart uploads count=118552026/09/23 13:24:05 OK 20260920000000_drop_claims.sql (14.07ms)18562026/09/23 13:24:05 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete18572026-09-23 13:24:05.084 UTC [62452] ERROR: Closure does not exist: id=118582026-09-23 13:24:05.084 UTC [62452] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 16 at RAISE18592026-09-23 13:24:05.084 UTC [62452] STATEMENT: -- name: CommitPendingClosure :exec1860 SELECT commit_pending_closure($1::bigint)1861 1862--- PASS: TestService_cleanupPendingClosuresHandler (3.05s)1863=== CONT TestOrphanedObjectsGCStressTest18642026/09/23 13:24:05 OK 20260923120000_add_pushes.sql (13.26ms)18652026/09/23 13:24:05 goose: successfully migrated database to version: 2026092312000018662026/09/23 13:24:05 OK 1_commit_pending_closure.sql (1.79ms)18672026/09/23 13:24:05 OK 2_object_stats_trigger.sql (450.96µs)18682026/09/23 13:24:05 OK 3_commit_push.sql (363.33µs)18692026/09/23 13:24:05 goose: up to current file version: 318702026/09/23 13:24:05 OK 20251218171726_add_pins.sql (36.32ms)18712026-09-23 13:24:05.124 UTC [62465] ERROR: relation "goose_db_version" does not exist at character 3618722026-09-23 13:24:05.124 UTC [62465] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18732026/09/23 13:24:05 OK 20260628120000_add_object_size_and_stats.sql (31.91ms)18742026/09/23 13:24:05 OK 20260905000000_add_claims.sql (26.32ms)18752026/09/23 13:24:05 OK 20260920000000_drop_claims.sql (28.4ms)18762026/09/23 13:24:05 OK 20260923120000_add_pushes.sql (13.81ms)18772026/09/23 13:24:05 goose: successfully migrated database to version: 2026092312000018782026/09/23 13:24:05 OK 1_commit_pending_closure.sql (3.71ms)18792026/09/23 13:24:05 OK 2_object_stats_trigger.sql (810.08µs)18802026/09/23 13:24:05 OK 3_commit_push.sql (612.96µs)18812026/09/23 13:24:05 goose: up to current file version: 318822026/09/23 13:24:05 INFO Received uploads request method=POST path=/api/pending_closures1883--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (2.93s)1884=== CONT TestOrphanedObjectsGC18852026/09/23 13:24:05 OK 20241026095416_initial_model.sql (131.58ms)18862026/09/23 13:24:05 OK 20251210153512_drop_unused_gin_index.sql (11.01ms)18872026/09/23 13:24:05 OK 20251218171726_add_pins.sql (13.82ms)18882026/09/23 13:24:05 OK 20260628120000_add_object_size_and_stats.sql (16.08ms)18892026/09/23 13:24:05 OK 20260905000000_add_claims.sql (26.19ms)18902026-09-23 13:24:05.377 UTC [62470] ERROR: relation "goose_db_version" does not exist at character 3618912026-09-23 13:24:05.377 UTC [62470] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18922026/09/23 13:24:05 OK 20260920000000_drop_claims.sql (18.56ms)18932026/09/23 13:24:05 OK 20260923120000_add_pushes.sql (16.55ms)18942026/09/23 13:24:05 goose: successfully migrated database to version: 2026092312000018952026/09/23 13:24:05 OK 1_commit_pending_closure.sql (2.68ms)18962026/09/23 13:24:05 OK 2_object_stats_trigger.sql (522.83µs)18972026/09/23 13:24:05 OK 3_commit_push.sql (390.67µs)18982026/09/23 13:24:05 goose: up to current file version: 318992026/09/23 13:24:05 INFO Received complete multipart upload request method=POST path=/api/multipart/complete19002026/09/23 13:24:05 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst1901--- PASS: TestCompleteMultipartUnregistered (2.78s)1902=== CONT TestObjectStatsTrigger19032026-09-23 13:24:05.509 UTC [62472] ERROR: relation "goose_db_version" does not exist at character 3619042026-09-23 13:24:05.509 UTC [62472] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC19052026/09/23 13:24:05 OK 20241026095416_initial_model.sql (92.42ms)19062026/09/23 13:24:05 OK 20251210153512_drop_unused_gin_index.sql (7.21ms)19072026/09/23 13:24:05 OK 20251218171726_add_pins.sql (40.57ms)19082026-09-23 13:24:05.572 UTC [62474] ERROR: relation "goose_db_version" does not exist at character 3619092026-09-23 13:24:05.572 UTC [62474] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC19102026/09/23 13:24:05 OK 20260628120000_add_object_size_and_stats.sql (19.5ms)19112026/09/23 13:24:05 OK 20260905000000_add_claims.sql (14.41ms)19122026/09/23 13:24:05 OK 20260920000000_drop_claims.sql (25.03ms)19132026/09/23 13:24:05 OK 20260923120000_add_pushes.sql (17.54ms)19142026/09/23 13:24:05 goose: successfully migrated database to version: 2026092312000019152026/09/23 13:24:05 OK 1_commit_pending_closure.sql (3.41ms)19162026/09/23 13:24:05 OK 2_object_stats_trigger.sql (604.42µs)19172026/09/23 13:24:05 OK 3_commit_push.sql (567.79µs)19182026/09/23 13:24:05 goose: up to current file version: 319192026/09/23 13:24:05 OK 20241026095416_initial_model.sql (109.7ms)19202026/09/23 13:24:05 OK 20251210153512_drop_unused_gin_index.sql (8.68ms)19212026/09/23 13:24:05 INFO Received uploads request method=POST path=/api/pending_closures19222026/09/23 13:24:05 OK 20251218171726_add_pins.sql (7.4ms)19232026/09/23 13:24:05 OK 20260628120000_add_object_size_and_stats.sql (36.57ms)19242026/09/23 13:24:05 OK 20241026095416_initial_model.sql (144.61ms)19252026/09/23 13:24:05 OK 20251210153512_drop_unused_gin_index.sql (11.7ms)19262026/09/23 13:24:05 OK 20260905000000_add_claims.sql (37.17ms)19272026/09/23 13:24:05 OK 20251218171726_add_pins.sql (7.16ms)19282026/09/23 13:24:05 OK 20260920000000_drop_claims.sql (22.66ms)19292026/09/23 13:24:05 OK 20260628120000_add_object_size_and_stats.sql (28.05ms)19302026/09/23 13:24:05 OK 20260923120000_add_pushes.sql (10.26ms)19312026/09/23 13:24:05 goose: successfully migrated database to version: 2026092312000019322026/09/23 13:24:05 OK 1_commit_pending_closure.sql (2.33ms)19332026/09/23 13:24:05 OK 2_object_stats_trigger.sql (516.71µs)19342026/09/23 13:24:05 OK 3_commit_push.sql (439.79µs)19352026/09/23 13:24:05 goose: up to current file version: 319362026/09/23 13:24:05 OK 20260905000000_add_claims.sql (37.94ms)19372026/09/23 13:24:05 OK 20260920000000_drop_claims.sql (24.8ms)19382026-09-23 13:24:05.865 UTC [62475] ERROR: relation "goose_db_version" does not exist at character 3619392026-09-23 13:24:05.865 UTC [62475] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC19402026/09/23 13:24:05 OK 20260923120000_add_pushes.sql (6.73ms)19412026/09/23 13:24:05 goose: successfully migrated database to version: 2026092312000019422026/09/23 13:24:05 OK 1_commit_pending_closure.sql (3.12ms)19432026/09/23 13:24:05 OK 2_object_stats_trigger.sql (643.08µs)19442026/09/23 13:24:05 OK 3_commit_push.sql (515.25µs)19452026/09/23 13:24:05 goose: up to current file version: 319462026/09/23 13:24:05 INFO Received uploads request method=POST path=/api/pending_closures19472026/09/23 13:24:05 INFO Received uploads request method=POST path=/api/pending_closures19482026/09/23 13:24:05 INFO Received uploads request method=POST path=/api/pending_closures19492026/09/23 13:24:06 OK 20241026095416_initial_model.sql (128.41ms)19502026/09/23 13:24:06 OK 20251210153512_drop_unused_gin_index.sql (1.96ms)19512026/09/23 13:24:06 OK 20251218171726_add_pins.sql (44.75ms)19522026/09/23 13:24:06 OK 20260628120000_add_object_size_and_stats.sql (43.62ms)19532026/09/23 13:24:06 OK 20260905000000_add_claims.sql (63.71ms)19542026/09/23 13:24:06 INFO lead: acquired remote=192.0.2.1:123419552026/09/23 13:24:06 INFO lead: released remote=192.0.2.1:12341956--- PASS: TestLeadEndsOnShutdown (2.63s)1957=== CONT TestMultipartCleanup19582026/09/23 13:24:06 OK 20260920000000_drop_claims.sql (56.33ms)19592026/09/23 13:24:06 OK 20260923120000_add_pushes.sql (32.39ms)19602026/09/23 13:24:06 goose: successfully migrated database to version: 2026092312000019612026/09/23 13:24:06 OK 1_commit_pending_closure.sql (2.18ms)19622026/09/23 13:24:06 OK 2_object_stats_trigger.sql (459.63µs)19632026/09/23 13:24:06 OK 3_commit_push.sql (413.79µs)19642026/09/23 13:24:06 goose: up to current file version: 319652026-09-23 13:24:06.400 UTC [62478] ERROR: relation "goose_db_version" does not exist at character 3619662026-09-23 13:24:06.400 UTC [62478] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC19672026/09/23 13:24:06 INFO Aborted multipart uploads count=019682026/09/23 13:24:06 WARN Force mode enabled - objects will be deleted immediately without grace period19692026/09/23 13:24:06 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=019702026/09/23 13:24:06 INFO Vacuumed table table=pending_closures19712026/09/23 13:24:06 INFO Vacuumed table table=pending_objects19722026/09/23 13:24:06 INFO Vacuumed table table=multipart_uploads19732026/09/23 13:24:06 INFO Vacuumed table table=closures19742026/09/23 13:24:06 INFO Vacuumed table table=objects1975--- PASS: TestGCMetrics (2.69s)1976=== CONT TestPresignedUploadRegisteredBeforeCommit19772026-09-23 13:24:06.611 UTC [62479] ERROR: relation "goose_db_version" does not exist at character 3619782026-09-23 13:24:06.611 UTC [62479] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC19792026/09/23 13:24:06 OK 20241026095416_initial_model.sql (162.84ms)19802026/09/23 13:24:06 OK 20251210153512_drop_unused_gin_index.sql (10.06ms)19812026/09/23 13:24:06 OK 20251218171726_add_pins.sql (38.89ms)19822026/09/23 13:24:06 OK 20260628120000_add_object_size_and_stats.sql (55.21ms)19832026/09/23 13:24:06 OK 20260905000000_add_claims.sql (22.91ms)19842026/09/23 13:24:06 OK 20260920000000_drop_claims.sql (32.92ms)19852026/09/23 13:24:06 OK 20260923120000_add_pushes.sql (30.67ms)19862026/09/23 13:24:06 goose: successfully migrated database to version: 2026092312000019872026/09/23 13:24:06 OK 1_commit_pending_closure.sql (2.62ms)19882026/09/23 13:24:06 OK 2_object_stats_trigger.sql (584.75µs)19892026/09/23 13:24:06 OK 3_commit_push.sql (388.42µs)19902026/09/23 13:24:06 goose: up to current file version: 319912026/09/23 13:24:06 OK 20241026095416_initial_model.sql (190.67ms)19922026/09/23 13:24:06 OK 20251210153512_drop_unused_gin_index.sql (17.73ms)19932026-09-23 13:24:06.905 UTC [62483] ERROR: relation "goose_db_version" does not exist at character 3619942026-09-23 13:24:06.905 UTC [62483] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC19952026/09/23 13:24:06 OK 20251218171726_add_pins.sql (18.47ms)19962026/09/23 13:24:06 OK 20260628120000_add_object_size_and_stats.sql (34.97ms)19972026/09/23 13:24:07 OK 20260905000000_add_claims.sql (64.78ms)19982026/09/23 13:24:07 OK 20260920000000_drop_claims.sql (14.1ms)19992026/09/23 13:24:07 OK 20260923120000_add_pushes.sql (8.3ms)20002026/09/23 13:24:07 goose: successfully migrated database to version: 2026092312000020012026/09/23 13:24:07 OK 1_commit_pending_closure.sql (2.14ms)20022026/09/23 13:24:07 OK 2_object_stats_trigger.sql (470.75µs)20032026/09/23 13:24:07 OK 3_commit_push.sql (424.42µs)20042026/09/23 13:24:07 goose: up to current file version: 32005--- PASS: TestGCBugBareHashReferences (2.89s)2006=== CONT TestProxyWriteTimeout2007=== RUN TestProxyWriteTimeout/narinfo2008=== PAUSE TestProxyWriteTimeout/narinfo2009=== RUN TestProxyWriteTimeout/1_GiB_nar2010=== PAUSE TestProxyWriteTimeout/1_GiB_nar2011=== RUN TestProxyWriteTimeout/10_GiB_nar2012=== PAUSE TestProxyWriteTimeout/10_GiB_nar2013=== RUN TestProxyWriteTimeout/unknown_size2014=== PAUSE TestProxyWriteTimeout/unknown_size2015=== CONT TestCreatePendingClosureRejectsOversizedNAR20162026/09/23 13:24:07 INFO Received uploads request method=POST path=/api/pending_closures2017--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)2018=== CONT TestService_NativeMTLS20192026/09/23 13:24:07 INFO Received complete multipart upload request method=POST path=/api/multipart/complete20202026/09/23 13:24:07 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux20212026/09/23 13:24:07 WARN Refused reserved pin name=worker-x86_64-linux20222026/09/23 13:24:07 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux20232026/09/23 13:24:07 INFO Received create pin request method=POST path=/api/pins/my-app20242026/09/23 13:24:07 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux2025--- PASS: TestCreatePin_ReservedPins (2.64s)2026=== CONT TestMetricsInventory20272026/09/23 13:24:07 OK 20241026095416_initial_model.sql (209.52ms)20282026/09/23 13:24:07 OK 20251210153512_drop_unused_gin_index.sql (16.64ms)20292026/09/23 13:24:07 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=YjI3YWFhNzYtOTcxMi00OTgzLWIwMmMtMjMwNjlmNGUzMmZiLjI4NmEwZTllLWM2NGEtNGY3NC1hMDc1LTliMTg2ZDEzYWNiOXgxNzkwMTY5ODQ1NzA0ODQwMDAw parts=1020302026/09/23 13:24:07 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete20312026/09/23 13:24:07 OK 20251218171726_add_pins.sql (21.58ms)20322026/09/23 13:24:07 INFO Completed upload id=120332026/09/23 13:24:07 INFO Received uploads request method=POST path=/api/pending_closures20342026/09/23 13:24:07 INFO Received uploads request method=POST path=/api/pending_closures20352026/09/23 13:24:07 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo20362026/09/23 13:24:07 WARN Found objects in DB but missing from S3, will re-upload count=12037--- PASS: TestService_verifyS3Integrity (4.26s)2038=== CONT TestNARDeduplicationMetadataUploadBug20392026/09/23 13:24:07 OK 20260628120000_add_object_size_and_stats.sql (58.62ms)20402026-09-23 13:24:07.298 UTC [62488] ERROR: relation "goose_db_version" does not exist at character 3620412026-09-23 13:24:07.298 UTC [62488] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC20422026/09/23 13:24:07 OK 20260905000000_add_claims.sql (38.26ms)20432026/09/23 13:24:07 OK 20260920000000_drop_claims.sql (14.8ms)20442026/09/23 13:24:07 OK 20260923120000_add_pushes.sql (20.9ms)20452026/09/23 13:24:07 goose: successfully migrated database to version: 2026092312000020462026/09/23 13:24:07 OK 1_commit_pending_closure.sql (1.8ms)20472026/09/23 13:24:07 OK 2_object_stats_trigger.sql (422.21µs)20482026/09/23 13:24:07 OK 3_commit_push.sql (376.58µs)20492026/09/23 13:24:07 goose: up to current file version: 320502026/09/23 13:24:07 INFO Received complete multipart upload request method=POST path=/api/multipart/complete20512026/09/23 13:24:07 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=YjI3YWFhNzYtOTcxMi00OTgzLWIwMmMtMjMwNjlmNGUzMmZiLmYyNmEyZWEyLTNlOWUtNGJhYS1iNGE0LTc5YWM2OTdkNzEyOHgxNzkwMTY5ODQ1OTY0ODUzMDAw parts=1020522026/09/23 13:24:07 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete20532026/09/23 13:24:07 OK 20241026095416_initial_model.sql (147.61ms)20542026/09/23 13:24:07 INFO Completed upload id=120552026/09/23 13:24:07 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000020562026/09/23 13:24:07 INFO Received uploads request method=POST path=/api/pending_closures20572026/09/23 13:24:07 INFO Starting cleanup of old closures method=DELETE path=/api/closures20582026/09/23 13:24:07 OK 20251210153512_drop_unused_gin_index.sql (14.71ms)20592026/09/23 13:24:07 INFO Aborted multipart uploads count=020602026/09/23 13:24:07 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=020612026/09/23 13:24:07 OK 20251218171726_add_pins.sql (24.44ms)20622026/09/23 13:24:07 INFO Vacuumed table table=pending_closures2063--- PASS: TestResurrectedObjectNotDeleted (2.62s)2064=== CONT TestResolveDBConnectionString2065=== RUN TestResolveDBConnectionString/flag_wins2066=== PAUSE TestResolveDBConnectionString/flag_wins2067=== RUN TestResolveDBConnectionString/file_when_flag_empty2068=== PAUSE TestResolveDBConnectionString/file_when_flag_empty2069=== RUN TestResolveDBConnectionString/missing_file_is_an_error2070=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error2071=== RUN TestResolveDBConnectionString/PGHOST_allows_empty2072=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty2073=== RUN TestResolveDBConnectionString/nothing_configured2074=== PAUSE TestResolveDBConnectionString/nothing_configured2075=== CONT TestLeadElectsOneAndHandsOver20762026/09/23 13:24:07 INFO Vacuumed table table=pending_objects20772026/09/23 13:24:07 OK 20260628120000_add_object_size_and_stats.sql (47.39ms)20782026/09/23 13:24:07 INFO Vacuumed table table=multipart_uploads20792026/09/23 13:24:07 INFO Vacuumed table table=closures20802026/09/23 13:24:07 OK 20260905000000_add_claims.sql (41.29ms)20812026/09/23 13:24:07 INFO Vacuumed table table=objects20822026/09/23 13:24:07 OK 20260920000000_drop_claims.sql (12.71ms)20832026/09/23 13:24:07 OK 20260923120000_add_pushes.sql (8.22ms)20842026/09/23 13:24:07 goose: successfully migrated database to version: 2026092312000020852026/09/23 13:24:07 OK 1_commit_pending_closure.sql (2.53ms)20862026/09/23 13:24:07 OK 2_object_stats_trigger.sql (544.79µs)20872026/09/23 13:24:07 OK 3_commit_push.sql (428.67µs)20882026/09/23 13:24:07 goose: up to current file version: 320892026/09/23 13:24:07 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000002090--- PASS: TestService_createPendingClosureHandler (4.35s)2091=== CONT TestGenerateLandingPage2092--- PASS: TestGenerateLandingPage (0.00s)2093=== CONT TestCacheConfigHandlerMaxNarSize2094--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)2095=== CONT TestService_readinessHandler20962026-09-23 13:24:08.201 UTC [62496] ERROR: relation "goose_db_version" does not exist at character 3620972026-09-23 13:24:08.201 UTC [62496] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC2098--- PASS: TestObjectStatsTrigger (2.77s)2099=== CONT TestClientFallsBackToClosures21002026-09-23 13:24:08.311 UTC [62499] ERROR: relation "goose_db_version" does not exist at character 3621012026-09-23 13:24:08.311 UTC [62499] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC21022026/09/23 13:24:08 OK 20241026095416_initial_model.sql (85.62ms)21032026/09/23 13:24:08 OK 20251210153512_drop_unused_gin_index.sql (7.91ms)21042026/09/23 13:24:08 OK 20251218171726_add_pins.sql (8.78ms)21052026/09/23 13:24:08 OK 20260628120000_add_object_size_and_stats.sql (24.48ms)21062026/09/23 13:24:08 OK 20260905000000_add_claims.sql (13.16ms)21072026/09/23 13:24:08 OK 20260920000000_drop_claims.sql (17.8ms)21082026/09/23 13:24:08 OK 20260923120000_add_pushes.sql (7.75ms)21092026/09/23 13:24:08 goose: successfully migrated database to version: 2026092312000021102026/09/23 13:24:08 OK 1_commit_pending_closure.sql (2.34ms)21112026/09/23 13:24:08 OK 2_object_stats_trigger.sql (501.29µs)21122026/09/23 13:24:08 OK 3_commit_push.sql (412.25µs)21132026/09/23 13:24:08 goose: up to current file version: 321142026/09/23 13:24:08 OK 20241026095416_initial_model.sql (109.69ms)21152026/09/23 13:24:08 OK 20251210153512_drop_unused_gin_index.sql (9.58ms)21162026/09/23 13:24:08 OK 20251218171726_add_pins.sql (8.03ms)21172026/09/23 13:24:08 OK 20260628120000_add_object_size_and_stats.sql (48.99ms)2118=== NAME TestOrphanedObjectsGC2119 orphaned_objects_gc_test.go:290: GC Test Summary:2120 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A2121 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B2122 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)2123 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)2124 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects2125--- PASS: TestOrphanedObjectsGC (3.26s)2126=== CONT TestService_Rustfstest21272026/09/23 13:24:08 OK 20260905000000_add_claims.sql (35.86ms)21282026/09/23 13:24:08 OK 20260920000000_drop_claims.sql (45.65ms)21292026/09/23 13:24:08 OK 20260923120000_add_pushes.sql (12.16ms)21302026/09/23 13:24:08 goose: successfully migrated database to version: 2026092312000021312026/09/23 13:24:08 OK 1_commit_pending_closure.sql (2.61ms)21322026/09/23 13:24:08 OK 2_object_stats_trigger.sql (567.38µs)21332026/09/23 13:24:08 OK 3_commit_push.sql (391.88µs)21342026/09/23 13:24:08 goose: up to current file version: 321352026/09/23 13:24:08 INFO Received uploads request method=POST path=/api/pending_closures21362026-09-23 13:24:08.828 UTC [62502] ERROR: relation "goose_db_version" does not exist at character 3621372026-09-23 13:24:08.828 UTC [62502] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC21382026/09/23 13:24:08 INFO Received cleanup request method=DELETE path=/api/pending_closures21392026/09/23 13:24:08 INFO Aborted multipart uploads count=12140--- PASS: TestMultipartCleanup (2.69s)2141=== CONT TestCacheConfigHandler/full_config,_no_issuer2142=== CONT TestCacheConfigHandler/no_signing_keys2143=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator2144=== CONT TestCacheConfigHandler/no_cache_url_configured2145--- PASS: TestCacheConfigHandler (0.00s)2146 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)2147 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)2148 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)2149 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)2150=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token2151=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected21522026/09/23 13:24:08 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]2153=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2154=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected21552026/09/23 13:24:08 WARN Authentication failed token_preview=eyJhbGciOi...QpcRnmSNMg token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]2156=== CONT TestService_RequireScope_OIDC/builder_may_write2157=== CONT TestService_RequireScope_OIDC/static_token_may_admin2158=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read2159=== CONT TestService_RequireScope_OIDC/writer_implies_read21602026-09-23 13:24:08.965 UTC [62503] ERROR: relation "goose_db_version" does not exist at character 3621612026-09-23 13:24:08.965 UTC [62503] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC2162=== CONT TestService_RequireScope_OIDC/reader_may_read2163=== CONT TestService_RequireScope_OIDC/static_token_may_write2164=== CONT TestService_RequireScope_OIDC/ops_may_not_write2165=== CONT TestService_RequireScope_OIDC/reader_may_not_write2166=== CONT TestService_RequireScope_OIDC/ops_may_admin2167=== CONT TestService_RequireScope_OIDC/builder_may_not_admin2168=== CONT TestClientErrorHandling/InvalidStorePath2169--- PASS: TestService_AuthMiddleware_OIDC (0.93s)2170 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)2171 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)2172 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)2173 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)2174--- PASS: TestService_RequireScope_OIDC (2.16s)2175 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)2176 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)2177 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)2178 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)2179 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)2180 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)2181 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)2182 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)2183 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)2184 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)21852026-09-23 13:24:08.978 UTC [62504] ERROR: relation "goose_db_version" does not exist at character 3621862026-09-23 13:24:08.978 UTC [62504] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC21872026/09/23 13:24:09 INFO Received uploads request method=POST path=/api/pending_closures21882026/09/23 13:24:09 OK 20241026095416_initial_model.sql (188.98ms)21892026/09/23 13:24:09 OK 20251210153512_drop_unused_gin_index.sql (7.81ms)21902026/09/23 13:24:09 OK 20251218171726_add_pins.sql (22.36ms)21912026/09/23 13:24:09 OK 20260628120000_add_object_size_and_stats.sql (16.75ms)21922026/09/23 13:24:09 OK 20241026095416_initial_model.sql (116.26ms)21932026/09/23 13:24:09 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst21942026/09/23 13:24:09 INFO Received uploads request method=POST path=/api/pending_closures21952026/09/23 13:24:09 OK 20251210153512_drop_unused_gin_index.sql (9.45ms)2196--- PASS: TestPresignedUploadRegisteredBeforeCommit (2.60s)2197=== CONT TestClientErrorHandling/ServerNotAvailable21982026/09/23 13:24:09 OK 20251218171726_add_pins.sql (20.9ms)21992026/09/23 13:24:09 OK 20260905000000_add_claims.sql (42.83ms)22002026/09/23 13:24:09 OK 20241026095416_initial_model.sql (95.04ms)22012026/09/23 13:24:09 OK 20260628120000_add_object_size_and_stats.sql (13.75ms)22022026/09/23 13:24:09 OK 20251210153512_drop_unused_gin_index.sql (5.45ms)22032026/09/23 13:24:09 OK 20260920000000_drop_claims.sql (12.07ms)22042026/09/23 13:24:09 OK 20260923120000_add_pushes.sql (8.11ms)22052026/09/23 13:24:09 goose: successfully migrated database to version: 2026092312000022062026-09-23 13:24:09.198 UTC [62508] ERROR: relation "goose_db_version" does not exist at character 3622072026-09-23 13:24:09.198 UTC [62508] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC22082026/09/23 13:24:09 OK 20251218171726_add_pins.sql (10ms)22092026/09/23 13:24:09 OK 1_commit_pending_closure.sql (1.55ms)22102026/09/23 13:24:09 OK 2_object_stats_trigger.sql (338.21µs)22112026/09/23 13:24:09 OK 3_commit_push.sql (261.29µs)22122026/09/23 13:24:09 goose: up to current file version: 322132026/09/23 13:24:09 OK 20260905000000_add_claims.sql (24.3ms)22142026/09/23 13:24:09 OK 20260628120000_add_object_size_and_stats.sql (23.23ms)22152026/09/23 13:24:09 OK 20260920000000_drop_claims.sql (15.93ms)22162026-09-23 13:24:09.228 UTC [62509] ERROR: relation "goose_db_version" does not exist at character 3622172026-09-23 13:24:09.228 UTC [62509] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC22182026/09/23 13:24:09 OK 20260923120000_add_pushes.sql (5.73ms)22192026/09/23 13:24:09 goose: successfully migrated database to version: 2026092312000022202026/09/23 13:24:09 OK 1_commit_pending_closure.sql (1.04ms)22212026/09/23 13:24:09 OK 2_object_stats_trigger.sql (245.79µs)22222026/09/23 13:24:09 OK 3_commit_push.sql (230.17µs)22232026/09/23 13:24:09 goose: up to current file version: 322242026/09/23 13:24:09 OK 20260905000000_add_claims.sql (48.15ms)22252026/09/23 13:24:09 OK 20260920000000_drop_claims.sql (28ms)22262026/09/23 13:24:09 OK 20260923120000_add_pushes.sql (22.1ms)22272026/09/23 13:24:09 goose: successfully migrated database to version: 2026092312000022282026/09/23 13:24:09 OK 1_commit_pending_closure.sql (1.38ms)22292026/09/23 13:24:09 OK 2_object_stats_trigger.sql (315.96µs)22302026/09/23 13:24:09 OK 3_commit_push.sql (285.21µs)22312026/09/23 13:24:09 goose: up to current file version: 322322026/09/23 13:24:09 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/present22332026/09/23 13:24:09 OK 20241026095416_initial_model.sql (143.94ms)22342026/09/23 13:24:09 OK 20251210153512_drop_unused_gin_index.sql (11.4ms)22352026/09/23 13:24:09 OK 20241026095416_initial_model.sql (136.18ms)22362026/09/23 13:24:09 OK 20251210153512_drop_unused_gin_index.sql (6.68ms)22372026/09/23 13:24:09 WARN mTLS auth: subject not in bound subjects subject="CN=reader"22382026/09/23 13:24:09 WARN mTLS auth: subject not in bound subjects subject="CN=reader"2239--- PASS: TestService_NativeMTLS (2.34s)2240=== CONT TestClientErrorHandling/InvalidAuthToken22412026/09/23 13:24:09 OK 20251218171726_add_pins.sql (36.8ms)22422026/09/23 13:24:09 OK 20251218171726_add_pins.sql (23.1ms)22432026/09/23 13:24:09 OK 20260628120000_add_object_size_and_stats.sql (36.34ms)22442026/09/23 13:24:09 OK 20260628120000_add_object_size_and_stats.sql (36.33ms)22452026/09/23 13:24:09 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=216.904583ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/objects/present22462026/09/23 13:24:09 OK 20260905000000_add_claims.sql (28.37ms)22472026/09/23 13:24:09 OK 20260905000000_add_claims.sql (28.43ms)22482026/09/23 13:24:09 OK 20260920000000_drop_claims.sql (29.65ms)22492026/09/23 13:24:09 OK 20260920000000_drop_claims.sql (30.44ms)22502026/09/23 13:24:09 OK 20260923120000_add_pushes.sql (13.06ms)22512026/09/23 13:24:09 goose: successfully migrated database to version: 2026092312000022522026/09/23 13:24:09 OK 1_commit_pending_closure.sql (1.53ms)22532026/09/23 13:24:09 OK 2_object_stats_trigger.sql (351.96µs)22542026/09/23 13:24:09 OK 3_commit_push.sql (307.71µs)22552026/09/23 13:24:09 goose: up to current file version: 322562026/09/23 13:24:09 OK 20260923120000_add_pushes.sql (19.12ms)22572026/09/23 13:24:09 goose: successfully migrated database to version: 2026092312000022582026/09/23 13:24:09 OK 1_commit_pending_closure.sql (1.71ms)22592026/09/23 13:24:09 OK 2_object_stats_trigger.sql (299.04µs)22602026/09/23 13:24:09 OK 3_commit_push.sql (303.5µs)22612026/09/23 13:24:09 goose: up to current file version: 322622026/09/23 13:24:09 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=377.142299ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/objects/present22632026-09-23 13:24:09.930 UTC [62517] ERROR: relation "goose_db_version" does not exist at character 3622642026-09-23 13:24:09.930 UTC [62517] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC2265=== NAME TestNARDeduplicationMetadataUploadBug2266 metadata_upload_test.go:48: First store path: /nix/var/nix/builds/nix-62151-941598581/TestNARDeduplicationMetadataUploadBug3086891092/001/store/lm19aqqlc24822pkhaydh87y4d4ivdv8-file1.txt2267--- PASS: TestMetricsInventory (2.82s)2268=== CONT TestPush_RejectsBadRequests/bad_root22692026/09/23 13:24:09 INFO Received push request method=POST path=/api/pushes2270=== CONT TestPush_RejectsBadRequests/no_roots22712026/09/23 13:24:09 INFO Received push request method=POST path=/api/pushes2272=== CONT TestPush_RejectsBadRequests/no_objects22732026/09/23 13:24:09 INFO Received push request method=POST path=/api/pushes2274=== CONT TestPush_RejectsBadRequests/root_not_in_objects22752026/09/23 13:24:09 INFO Received push request method=POST path=/api/pushes2276=== CONT TestIsValidCachePath/narinfo2277--- PASS: TestPush_RejectsBadRequests (1.61s)2278 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)2279 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)2280 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)2281 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)2282=== CONT TestIsValidCachePath/index.html2283=== CONT TestIsValidCachePath/short_hash2284=== CONT TestIsValidCachePath/wrong_extension2285=== CONT TestIsValidCachePath/leading_slash2286=== CONT TestIsValidCachePath/empty2287=== CONT TestIsValidCachePath/random_path2288=== CONT TestIsValidCachePath/invalid_char_u2289=== CONT TestIsValidCachePath/traversal_parent2290=== CONT TestIsValidCachePath/invalid_char_e2291=== CONT TestIsValidCachePath/nar_uncompressed2292=== CONT TestIsValidCachePath/nix-cache-info2293=== CONT TestIsValidCachePath/realisation2294=== CONT TestIsValidCachePath/log2295=== CONT TestIsValidCachePath/ls2296=== CONT TestIsValidCachePath/nar_xz2297=== CONT TestIsValidCachePath/nar_bz22298=== CONT TestIsValidCachePath/nar_zst2299=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars2300=== CONT TestIsValidCachePath/traversal_in_middle2301--- PASS: TestIsValidCachePath (0.00s)2302 --- PASS: TestIsValidCachePath/narinfo (0.00s)2303 --- PASS: TestIsValidCachePath/index.html (0.00s)2304 --- PASS: TestIsValidCachePath/short_hash (0.00s)2305 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)2306 --- PASS: TestIsValidCachePath/leading_slash (0.00s)2307 --- PASS: TestIsValidCachePath/empty (0.00s)2308 --- PASS: TestIsValidCachePath/random_path (0.00s)2309 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)2310 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)2311 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)2312 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)2313 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)2314 --- PASS: TestIsValidCachePath/realisation (0.00s)2315 --- PASS: TestIsValidCachePath/log (0.00s)2316 --- PASS: TestIsValidCachePath/ls (0.00s)2317 --- PASS: TestIsValidCachePath/nar_xz (0.00s)2318 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)2319 --- PASS: TestIsValidCachePath/nar_zst (0.00s)2320 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)2321 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)2322=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info23232026/09/23 13:24:09 INFO Received uploads request method=POST path=/2324=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key23252026/09/23 13:24:09 INFO Received complete multipart upload request method=POST path=/2326=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key23272026/09/23 13:24:09 INFO Received request for more parts method=POST path=/2328=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal23292026/09/23 13:24:09 INFO Received uploads request method=POST path=/2330--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)2331 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)2332 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)2333 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)2334 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)2335=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure23362026/09/23 13:24:09 INFO Received uploads request method=POST path=/23372026/09/23 13:24:10 INFO Received uploads request method=POST path=/api/pending_closures23382026/09/23 13:24:10 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=755.997017ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/objects/present23392026/09/23 13:24:10 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)23402026/09/23 13:24:10 INFO Uploading lm19aqqlc24822pkhaydh87y4d4ivdv8-file1.txt (160B)23412026/09/23 13:24:10 WARN Failed to register uploaded object key=lm19aqqlc24822pkhaydh87y4d4ivdv8.ls error="server returned 404: 404 page not found\n"23422026/09/23 13:24:10 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign23432026/09/23 13:24:10 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"23442026/09/23 13:24:10 INFO Signed narinfos id=1 count=123452026/09/23 13:24:10 INFO Uploading 1 narinfos23462026/09/23 13:24:10 OK 20241026095416_initial_model.sql (127.12ms)23472026/09/23 13:24:10 OK 20251210153512_drop_unused_gin_index.sql (5.26ms)23482026/09/23 13:24:10 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete23492026/09/23 13:24:10 WARN Failed to register uploaded object key=lm19aqqlc24822pkhaydh87y4d4ivdv8.narinfo error="server returned 404: 404 page not found\n"23502026/09/23 13:24:10 INFO Completed upload id=123512026/09/23 13:24:10 INFO Upload complete. (115ms)2352=== NAME TestNARDeduplicationMetadataUploadBug2353 metadata_upload_test.go:54: Retrieved narinfo from S3:2354 StorePath: /nix/var/nix/builds/nix-62151-941598581/TestNARDeduplicationMetadataUploadBug3086891092/001/store/lm19aqqlc24822pkhaydh87y4d4ivdv8-file1.txt2355 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst2356 Compression: zstd2357 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf2358 NarSize: 1602359 References: 2360 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf2361 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)2362 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):2363 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}23642026/09/23 13:24:10 OK 20251218171726_add_pins.sql (30.17ms)23652026/09/23 13:24:10 INFO lead: acquired remote=192.0.2.1:123423662026/09/23 13:24:10 OK 20260628120000_add_object_size_and_stats.sql (28.38ms)2367 metadata_upload_test.go:64: Second store path (same content): /nix/var/nix/builds/nix-62151-941598581/TestNARDeduplicationMetadataUploadBug3086891092/001/store/ks47l7sk2qdpa3lghqfn5pz4w32m0q6l-file2.txt23682026/09/23 13:24:10 OK 20260905000000_add_claims.sql (31.55ms)23692026/09/23 13:24:10 OK 20260920000000_drop_claims.sql (12.07ms)23702026-09-23 13:24:10.221 UTC [62525] ERROR: relation "goose_db_version" does not exist at character 3623712026-09-23 13:24:10.221 UTC [62525] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC23722026/09/23 13:24:10 OK 20260923120000_add_pushes.sql (9.58ms)23732026/09/23 13:24:10 goose: successfully migrated database to version: 2026092312000023742026/09/23 13:24:10 OK 1_commit_pending_closure.sql (920µs)23752026/09/23 13:24:10 OK 2_object_stats_trigger.sql (232.67µs)23762026/09/23 13:24:10 OK 3_commit_push.sql (172.04µs)23772026/09/23 13:24:10 goose: up to current file version: 323782026/09/23 13:24:10 INFO Received uploads request method=POST path=/api/pending_closures23792026/09/23 13:24:10 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)2380=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts23812026/09/23 13:24:10 INFO Received request for more parts method=POST path=/2382=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart23832026/09/23 13:24:10 INFO Received complete multipart upload request method=POST path=/23842026/09/23 13:24:10 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign23852026/09/23 13:24:10 INFO Signed narinfos id=2 count=123862026/09/23 13:24:10 INFO Uploading 1 narinfos23872026/09/23 13:24:10 WARN Failed to register uploaded object key=ks47l7sk2qdpa3lghqfn5pz4w32m0q6l.ls error="server returned 404: 404 page not found\n"2388=== CONT TestIsValidUploadKey/narinfo2389=== CONT TestIsValidUploadKey/realisation_plus_in_output2390=== CONT TestIsValidUploadKey/unknown_type2391=== CONT TestIsValidUploadKey/empty_key2392=== CONT TestIsValidUploadKey/absolute2393=== CONT TestIsValidUploadKey/traversal_nar2394=== CONT TestIsValidUploadKey/traversal2395=== CONT TestIsValidUploadKey/listing_key,_narinfo_type2396--- PASS: TestUploadHandlersRejectOversizedBody (0.04s)2397 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.29s)2398 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.02s)2399 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.02s)2400=== CONT TestIsValidUploadKey/nar_key,_narinfo_type2401=== CONT TestIsValidUploadKey/narinfo_key,_nar_type2402=== CONT TestIsValidUploadKey/index.html2403=== CONT TestIsValidUploadKey/nix-cache-info2404=== CONT TestIsValidUploadKey/build_log_home-manager_file2405=== CONT TestIsValidUploadKey/realisation2406=== CONT TestIsValidUploadKey/build_log_equals2407=== CONT TestIsValidUploadKey/build_log_question_mark2408=== CONT TestIsValidUploadKey/build_log_plus_in_name2409=== CONT TestIsValidUploadKey/nar_plain2410=== CONT TestIsValidUploadKey/build_log2411=== CONT TestIsValidUploadKey/listing2412=== CONT TestIsValidUploadKey/nar_xz2413=== CONT TestIsValidUploadKey/nar_zst2414--- PASS: TestIsValidUploadKey (0.00s)2415 --- PASS: TestIsValidUploadKey/narinfo (0.00s)2416 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)2417 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)2418 --- PASS: TestIsValidUploadKey/empty_key (0.00s)2419 --- PASS: TestIsValidUploadKey/absolute (0.00s)2420 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)2421 --- PASS: TestIsValidUploadKey/traversal (0.00s)2422 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)2423 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)2424 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)2425 --- PASS: TestIsValidUploadKey/index.html (0.00s)2426 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)2427 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)2428 --- PASS: TestIsValidUploadKey/realisation (0.00s)2429 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)2430 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)2431 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)2432 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)2433 --- PASS: TestIsValidUploadKey/build_log (0.00s)2434 --- PASS: TestIsValidUploadKey/listing (0.00s)2435 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)2436 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)2437=== CONT TestServerTLSConfig/no_client_CA2438=== CONT TestServerTLSConfig/not_a_PEM_file2439=== CONT TestServerTLSConfig/missing_CA_file2440--- PASS: TestServerTLSConfig (0.00s)2441 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)2442 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.01s)2443 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)2444=== CONT TestParseSingleRange/none2445=== CONT TestParseSingleRange/open-ended2446=== CONT TestParseSingleRange/start_far_past_EOF2447=== CONT TestParseSingleRange/start_past_EOF2448=== CONT TestParseSingleRange/single_byte2449=== CONT TestParseSingleRange/suffix_exceeds_size2450=== CONT TestParseSingleRange/suffix2451=== CONT TestParseSingleRange/end_clamped_to_size2452=== CONT TestParseSingleRange/malformed_both_empty2453=== CONT TestParseSingleRange/closed2454=== CONT TestParseSingleRange/malformed_end_before_start2455=== CONT TestParseSingleRange/multi-range_ignored2456=== CONT TestParseSingleRange/malformed_no_dash2457=== CONT TestParseSingleRange/unknown_unit2458--- PASS: TestParseSingleRange (0.00s)2459 --- PASS: TestParseSingleRange/none (0.00s)2460 --- PASS: TestParseSingleRange/open-ended (0.00s)2461 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)2462 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)2463 --- PASS: TestParseSingleRange/single_byte (0.00s)2464 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)2465 --- PASS: TestParseSingleRange/suffix (0.00s)2466 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)2467 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)2468 --- PASS: TestParseSingleRange/closed (0.00s)2469 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)2470 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)2471 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)2472 --- PASS: TestParseSingleRange/unknown_unit (0.00s)2473=== CONT TestProxyWriteTimeout/narinfo2474=== CONT TestProxyWriteTimeout/10_GiB_nar2475=== CONT TestProxyWriteTimeout/unknown_size2476=== CONT TestProxyWriteTimeout/1_GiB_nar2477--- PASS: TestProxyWriteTimeout (0.00s)2478 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)2479 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)2480 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)2481 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)2482=== CONT TestResolveDBConnectionString/flag_wins2483=== CONT TestResolveDBConnectionString/PGHOST_allows_empty2484=== CONT TestResolveDBConnectionString/nothing_configured2485=== CONT TestResolveDBConnectionString/missing_file_is_an_error2486=== CONT TestResolveDBConnectionString/file_when_flag_empty24872026/09/23 13:24:10 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete24882026/09/23 13:24:10 INFO lead: released remote=192.0.2.1:123424892026/09/23 13:24:10 WARN Failed to register uploaded object key=ks47l7sk2qdpa3lghqfn5pz4w32m0q6l.narinfo error="server returned 404: 404 page not found\n"2490--- PASS: TestResolveDBConnectionString (0.02s)2491 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)2492 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)2493 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)2494 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)2495 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)24962026/09/23 13:24:10 INFO Completed upload id=224972026/09/23 13:24:10 INFO Upload complete. (87ms)2498=== NAME TestNARDeduplicationMetadataUploadBug2499 metadata_upload_test.go:76: Retrieved narinfo from S3:2500 StorePath: /nix/var/nix/builds/nix-62151-941598581/TestNARDeduplicationMetadataUploadBug3086891092/001/store/ks47l7sk2qdpa3lghqfn5pz4w32m0q6l-file2.txt2501 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst2502 Compression: zstd2503 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf2504 NarSize: 1602505 References: 2506 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf2507 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)2508 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):2509 {"version":1,"root":{"type":"regular","size":44}}2510--- PASS: TestNARDeduplicationMetadataUploadBug (3.13s)25112026/09/23 13:24:10 INFO lead: acquired remote=192.0.2.1:123425122026-09-23 13:24:10.373 UTC [62530] ERROR: relation "goose_db_version" does not exist at character 3625132026-09-23 13:24:10.373 UTC [62530] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC25142026/09/23 13:24:10 INFO lead: released remote=192.0.2.1:12342515--- PASS: TestLeadElectsOneAndHandsOver (2.83s)25162026/09/23 13:24:10 OK 20241026095416_initial_model.sql (113.79ms)25172026/09/23 13:24:10 OK 20251210153512_drop_unused_gin_index.sql (6.93ms)25182026/09/23 13:24:10 WARN readiness check failed error="closed pool"2519--- PASS: TestService_readinessHandler (2.76s)25202026/09/23 13:24:10 OK 20251218171726_add_pins.sql (23.23ms)25212026/09/23 13:24:10 OK 20260628120000_add_object_size_and_stats.sql (36.41ms)25222026/09/23 13:24:10 OK 20260905000000_add_claims.sql (31.22ms)25232026/09/23 13:24:10 OK 20260920000000_drop_claims.sql (32.8ms)25242026/09/23 13:24:10 OK 20260923120000_add_pushes.sql (19.06ms)25252026/09/23 13:24:10 goose: successfully migrated database to version: 2026092312000025262026/09/23 13:24:10 OK 1_commit_pending_closure.sql (3.05ms)25272026/09/23 13:24:10 OK 2_object_stats_trigger.sql (634.33µs)25282026/09/23 13:24:10 OK 3_commit_push.sql (420.92µs)25292026/09/23 13:24:10 goose: up to current file version: 325302026/09/23 13:24:10 OK 20241026095416_initial_model.sql (172.51ms)25312026/09/23 13:24:10 OK 20251210153512_drop_unused_gin_index.sql (7.36ms)25322026/09/23 13:24:10 OK 20251218171726_add_pins.sql (30.35ms)25332026/09/23 13:24:10 OK 20260628120000_add_object_size_and_stats.sql (37.65ms)25342026/09/23 13:24:10 OK 20260905000000_add_claims.sql (58.09ms)25352026/09/23 13:24:10 OK 20260920000000_drop_claims.sql (23.8ms)25362026/09/23 13:24:10 OK 20260923120000_add_pushes.sql (9.61ms)25372026/09/23 13:24:10 goose: successfully migrated database to version: 2026092312000025382026/09/23 13:24:10 OK 1_commit_pending_closure.sql (1.16ms)25392026/09/23 13:24:10 OK 2_object_stats_trigger.sql (296.17µs)25402026/09/23 13:24:10 OK 3_commit_push.sql (231.96µs)25412026/09/23 13:24:10 goose: up to current file version: 325422026-09-23 13:24:10.836 UTC [62534] ERROR: relation "goose_db_version" does not exist at character 3625432026-09-23 13:24:10.836 UTC [62534] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC25442026/09/23 13:24:10 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.4656317s error="Post \"http://localhost:19999/api/objects/present\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2545--- PASS: TestService_Rustfstest (2.35s)25462026/09/23 13:24:10 OK 20241026095416_initial_model.sql (100.89ms)25472026/09/23 13:24:10 OK 20251210153512_drop_unused_gin_index.sql (5.06ms)25482026/09/23 13:24:11 OK 20251218171726_add_pins.sql (20.73ms)25492026/09/23 13:24:11 OK 20260628120000_add_object_size_and_stats.sql (14.02ms)25502026/09/23 13:24:11 OK 20260905000000_add_claims.sql (31.96ms)25512026/09/23 13:24:11 OK 20260920000000_drop_claims.sql (18.53ms)25522026/09/23 13:24:11 OK 20260923120000_add_pushes.sql (4.42ms)25532026/09/23 13:24:11 goose: successfully migrated database to version: 2026092312000025542026/09/23 13:24:11 OK 1_commit_pending_closure.sql (896.38µs)25552026/09/23 13:24:11 OK 2_object_stats_trigger.sql (228.5µs)25562026/09/23 13:24:11 OK 3_commit_push.sql (192.83µs)25572026/09/23 13:24:11 goose: up to current file version: 325582026/09/23 13:24:11 INFO Received uploads request method=POST path=/api/pending_closures25592026/09/23 13:24:11 INFO Received uploads request method=POST path=/api/pending_closures25602026/09/23 13:24:11 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)25612026/09/23 13:24:11 INFO Uploading rix4npai4h5h44bvd3rj54gz10fs6asm-shared-dep (136B)25622026/09/23 13:24:11 INFO Uploading d807x8ipqmrfwkkp01w5zriknqh4c3ns-b (248B)25632026/09/23 13:24:11 WARN Failed to register uploaded object key=rix4npai4h5h44bvd3rj54gz10fs6asm.ls error="server returned 404: 404 page not found\n"25642026/09/23 13:24:11 WARN Failed to register uploaded object key=d807x8ipqmrfwkkp01w5zriknqh4c3ns.ls error="server returned 404: 404 page not found\n"25652026/09/23 13:24:11 WARN Failed to register uploaded object key=a6bcw3dq5w1aipszg9v7pmr1wgkl1kh0.ls error="server returned 404: 404 page not found\n"25662026/09/23 13:24:11 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign25672026/09/23 13:24:11 WARN Failed to register uploaded object key=nar/0k497dbzmrrjnnd8dzvvqcg1lg5022sm20wihxdzyrzf84w42fiy.nar.zst error="server returned 404: 404 page not found\n"25682026/09/23 13:24:11 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"25692026/09/23 13:24:11 INFO Signed narinfos id=2 count=225702026/09/23 13:24:11 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign25712026/09/23 13:24:11 INFO Signed narinfos id=1 count=225722026/09/23 13:24:11 INFO Uploading 4 narinfos25732026/09/23 13:24:11 WARN Failed to register uploaded object key=rix4npai4h5h44bvd3rj54gz10fs6asm.narinfo error="server returned 404: 404 page not found\n"25742026/09/23 13:24:11 WARN Failed to register uploaded object key=d807x8ipqmrfwkkp01w5zriknqh4c3ns.narinfo error="server returned 404: 404 page not found\n"25752026/09/23 13:24:11 WARN Failed to register uploaded object key=a6bcw3dq5w1aipszg9v7pmr1wgkl1kh0.narinfo error="server returned 404: 404 page not found\n"25762026/09/23 13:24:11 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete25772026/09/23 13:24:11 WARN Failed to register uploaded object key=rix4npai4h5h44bvd3rj54gz10fs6asm.narinfo error="server returned 404: 404 page not found\n"25782026/09/23 13:24:11 INFO Completed upload id=125792026/09/23 13:24:11 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete25802026/09/23 13:24:11 INFO Completed upload id=225812026/09/23 13:24:11 INFO Upload complete. (120ms)2582=== NAME TestClientFallsBackToClosures2583 client_pushes_test.go:112: Retrieved narinfo from S3:2584 StorePath: /nix/var/nix/builds/nix-62151-941598581/TestClientFallsBackToClosures3641841813/001/store/rix4npai4h5h44bvd3rj54gz10fs6asm-shared-dep2585 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst2586 Compression: zstd2587 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y822588 NarSize: 1362589 References: 2590 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n2591 client_pushes_test.go:112: Retrieved narinfo from S3:2592 StorePath: /nix/var/nix/builds/nix-62151-941598581/TestClientFallsBackToClosures3641841813/001/store/a6bcw3dq5w1aipszg9v7pmr1wgkl1kh0-a2593 URL: nar/0k497dbzmrrjnnd8dzvvqcg1lg5022sm20wihxdzyrzf84w42fiy.nar.zst2594 Compression: zstd2595 NarHash: sha256:0k497dbzmrrjnnd8dzvvqcg1lg5022sm20wihxdzyrzf84w42fiy2596 NarSize: 2482597 References: /nix/var/nix/builds/nix-62151-941598581/TestClientFallsBackToClosures3641841813/001/store/rix4npai4h5h44bvd3rj54gz10fs6asm-shared-dep2598 CA: text:sha256:0n46gprka044zyv8a1p1cazl6g6qp71150mmg7cc8x874024qga82599 client_pushes_test.go:112: Retrieved narinfo from S3:2600 StorePath: /nix/var/nix/builds/nix-62151-941598581/TestClientFallsBackToClosures3641841813/001/store/d807x8ipqmrfwkkp01w5zriknqh4c3ns-b2601 URL: nar/0k497dbzmrrjnnd8dzvvqcg1lg5022sm20wihxdzyrzf84w42fiy.nar.zst2602 Compression: zstd2603 NarHash: sha256:0k497dbzmrrjnnd8dzvvqcg1lg5022sm20wihxdzyrzf84w42fiy2604 NarSize: 2482605 References: /nix/var/nix/builds/nix-62151-941598581/TestClientFallsBackToClosures3641841813/001/store/rix4npai4h5h44bvd3rj54gz10fs6asm-shared-dep2606 CA: text:sha256:0n46gprka044zyv8a1p1cazl6g6qp71150mmg7cc8x874024qga82607--- PASS: TestClientFallsBackToClosures (3.01s)26082026/09/23 13:24:11 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"26092026/09/23 13:24:11 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"2610=== NAME TestOrphanedObjectsGCStressTest2611 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains2612 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion2613 orphaned_objects_gc_test.go:509: Stress test completed successfully:2614 orphaned_objects_gc_test.go:510: - Active objects preserved: 202615 orphaned_objects_gc_test.go:511: - Objects deleted: 2102616 orphaned_objects_gc_test.go:512: - Total GC'd: 2102617--- PASS: TestOrphanedObjectsGCStressTest (6.57s)26182026/09/23 13:24:12 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-config26192026/09/23 13:24:12 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=219.691031ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config26202026/09/23 13:24:12 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=402.808767ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config26212026/09/23 13:24:13 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=731.07839ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config26222026/09/23 13:24:13 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.521050909s error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config26232026/09/23 13:24:15 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"26242026/09/23 13:24:15 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_closures26252026/09/23 13:24:15 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=200.77378ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures26262026/09/23 13:24:15 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=376.776577ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures26272026/09/23 13:24:16 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=837.873619ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures26282026/09/23 13:24:16 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.447372389s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2629--- PASS: TestClientErrorHandling (0.00s)2630 --- PASS: TestClientErrorHandling/InvalidStorePath (2.16s)2631 --- PASS: TestClientErrorHandling/InvalidAuthToken (2.03s)2632 --- PASS: TestClientErrorHandling/ServerNotAvailable (9.21s)2633FAIL2634{"timestamp":"2026-09-23T13:24:18.354408Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:58564","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(10)"}26352026-09-23 13:24:18.511 UTC [62188] LOG: received smart shutdown request26362026-09-23 13:24:18.512 UTC [62188] LOG: background worker "logical replication launcher" (PID 62198) exited with exit code 126372026-09-23 13:24:18.517 UTC [62193] LOG: shutting down26382026-09-23 13:24:18.517 UTC [62193] LOG: checkpoint starting: shutdown immediate26392026-09-23 13:24:19.682 UTC [62193] LOG: checkpoint complete: wrote 13040 buffers (79.6%), wrote 4 SLRU buffers; 0 WAL file(s) added, 0 removed, 18 recycled; write=0.737 s, sync=0.371 s, total=1.165 s; sync files=21875, longest=0.001 s, average=0.001 s; distance=302641 kB, estimate=302641 kB; lsn=0/13F19550, redo lsn=0/13F1955026402026-09-23 13:24:19.687 UTC [62188] LOG: database system is shut down