penpot/backend/test/backend_tests/objects_gc_test.clj
Andrey Antukh 8b441be02f 💥 Partition file_change by file_id
`file_change` is the biggest relation of the database: 683 GB in
production, of which almost all the TOAST is dead space (the legacy
data is already migrated to `file_data`; what is left is the xlog of
the revisions, 4.4 kB on average). It grows with every save of a file
and every version, and its rows are spread over the whole table, so
every query that filters by a file has to walk all of it.

The table is now partitioned by `HASH (file_id)` with 16 partitions, the
same bounds as `file_data`, so the queries that filter by a file can
prune to one partition and the join between the two tables is resolved
partition by partition. The primary key has to include the partition
key, so it becomes `(file_id, id)`, and every access path of the table
filters by `file_id` accordingly: the snapshot commands require it
(2.19), the frontend sends it, and the garbage collector locks the
pending rows by their `(file_id, id)` pair.

The migration creates the partitioned table with the final schema and
copies the rows, keeping the old one aside as `file_change_legacy` for
the rollback. The copy happens inside the transaction of the migration,
so it does not fit a big instance: there the migration is marked as
applied and the procedure of `operations/` does it by hand, in phases,
driven by the `updated_at` watermark.

Along the way:

- every mutation of the table moves `updated_at` to the moment of the
  mutation, so the phased copy does not lose the rows changed while it
  runs. It is never set to the `deleted_at` of the row, which for the
  system snapshots is a date in the future.
- a new `kind` column tells the snapshots (1) and the revisions (2) of
  the table apart, and the two paths that insert in it fill it. It has
  no default on purpose, so an insert that forgets it fails instead of
  storing the wrong kind silently. It is a reserve: the queries still
  tell a snapshot from a revision by its label, and no constraint ties
  the two together.
- the revision does not repeat the features of the file anymore: they
  were 348 bytes written on every save and nobody read them from there.
- the legacy file data backend is gone, and with it the `data`,
  `data_ref_id` and `data_backend` columns, which nobody wrote anymore.
- the migration copies the legacy blobs of the snapshots to `file_data`
  before the column goes away, and stops when a snapshot with legacy
  data is left without its blob: the backend is better down than losing
  content.
- the foreign key of the legacy table on `file_id` goes away with the
  copy: it is `NO ACTION`, so while the legacy table has rows, the
  objects GC cannot delete the files they point to.
- the quota of the snapshots of a team resolves the files of the team
  first and counts their versions with `= ANY`, instead of joining the
  team with every version of the table.
- the pool sets `enable_partitionwise_join` on every connection, so the
  join between the two partitioned tables is resolved partition by
  partition.
- the snapshot lookup reports an unknown snapshot with its own error
  instead of the generic "object not found" of the database helper, and
  the decode script fails instead of printing an empty JSON.
- the procedure of `operations/` stops the backend and the workers
  during the cutover: the pool keeps server-side prepared statements,
  and a prepared statement holds the OID of the table it was prepared
  with, so a connection would keep writing to the legacy table after
  the rename.
- the procedure creates the partitions with their final name, so the
  result is the schema a new installation gets, and its verification
  checks the names and not only how many there are.
- the index of the system snapshots is gone: it filtered them by
  `deleted_at IS NULL`, and they always carry a deletion date in the
  future, so it never matched a row.
- the configuration guide, the memories and the docstring of the decode
  script say that the `legacy-db` backend is gone, instead of offering
  a value that takes the service down.
- a test fixes the schema the migration leaves: the 16 partitions with
  their name, the primary key, the foreign keys, the check of the kind,
  the six indexes, the absence of the legacy columns, and that an insert
  without a kind or with an unknown one fails.

Closes #12416

AI-assisted-by: glm-5.3-flash
AI-assisted-by: minimax-m3.1-flash
2026-10-30 10:57:34 +01:00

265 lines
12 KiB
Clojure

;; This Source Code Form is subject to the terms of the Mozilla Public
;; License, v. 2.0. If a copy of the MPL was not distributed with this
;; file, You can obtain one at http://mozilla.org/MPL/2.0/.
;;
;; Copyright (c) KALEIDOS INC Sucursal en España SL
(ns backend-tests.objects-gc-test
(:require
[app.common.logging :as l]
[app.common.time :as ct]
[app.config :as cf]
[app.db :as db]
[app.features.file-changes :as fchanges]
[app.rpc :as-alias rpc]
[app.storage :as sto]
[app.tasks.objects-gc :as ogc]
[backend-tests.helpers :as th]
[clojure.test :as t]
[mockery.core :refer [with-mocks]]))
(t/use-fixtures :once th/state-init)
(t/use-fixtures :each th/database-reset)
(defn- create-deleted-file!
"Creates a file and applies the deletion cascade on it (the same task the RPC
uses), so its children are marked as deleted for the given date. Returns the
file."
[profile i deleted-at]
(let [file (th/create-file* i {:profile-id (:id profile)
:project-id (:default-project-id profile)})]
(th/run-task! :delete-object {:object :file
:deleted-at deleted-at
:id (:id file)})
file))
(defn- block-file!
"Leaves an unmarked `file_media_object` pointing at the file, which is what
happens in production: a child that the deletion cascade did not mark. Its
foreign key towards `file` is `NO ACTION`, so it blocks the file deletion."
[file]
(let [media (sto/put-object! (::sto/storage th/*system*)
{::sto/content (sto/content "media")
:content-type "text/plain"
:bucket "file-media-object"})]
(th/create-file-media-object* {:file-id (:id file)
:media-id (:id media)})))
(defn- find-file
[id]
(th/db-get :file {:id id} {::db/remove-deleted false}))
(defn- chunk-error
"The first captured log record that reports a skipped chunk for `obj`,
waiting for it because logging is asynchronous."
[records obj]
(let [deadline (+ (System/currentTimeMillis) 5000)]
(loop []
(let [record (first (filter (fn [record]
(let [props (::l/props record)]
(and (= obj (get props :obj))
(= "error on chunk deletion, skipping it"
(get props :hint)))))
@records))]
(cond
record record
(> (System/currentTimeMillis) deadline) nil
:else (do (Thread/sleep 10) (recur)))))))
(t/deftest deletes-the-pending-files
(let [profile (th/create-profile* 1)
file (create-deleted-file! profile 1 (ct/in-past "10m"))
result (th/run-task! :objects-gc {})]
(t/is (pos? (:processed result)))
(t/is (nil? (find-file (:id file))))))
(t/deftest deletes-the-pending-file-changes
;; The pending file changes are locked and deleted by their (file-id, id)
;; pair, so the rows of a file that is pending deletion are gone after the
;; run.
(let [profile (th/create-profile* 1)
file (th/create-file* 1 {:profile-id (:id profile)
:project-id (:default-project-id profile)})
_ (th/db-insert! :file-change
{:file-id (:id file)
:kind fchanges/revision-kind
:deleted-at (ct/in-past "10m")})
result (th/run-task! :objects-gc {})]
(t/is (pos? (:processed result)))
(t/is (nil? (th/db-get :file-change {:file-id (:id file)}
{::db/remove-deleted false})))))
(t/deftest profile-cascade-keeps-profile-deletion-date
;; The cascade marks the owned rows with the deletion date of the profile,
;; like the RPC delete-profile flow does, not with the timestamp of the run.
;; The team survives because only the profiles chunk runs here, so its row
;; still shows that date.
(let [profile (th/create-profile* 1)
_ (th/db-update! :profile {:deleted-at (ct/in-past "30m")} {:id (:id profile)})
deleted-at (:deleted-at (th/db-get :profile {:id (:id profile)}
{::db/remove-deleted false}))
cfg {::db/pool th/*pool*
::sto/storage (::sto/storage th/*system*)
::ogc/timestamp deleted-at}
total (#'ogc/delete-profiles-chunk cfg [(:id profile)])]
(t/testing "the profile is gone and the chunk reports it"
(t/is (= 1 total))
(t/is (nil? (th/db-get :profile {:id (:id profile)} {::db/remove-deleted false}))))
(t/testing "the owned team keeps the deletion date of the profile"
(t/is (= deleted-at (:deleted-at (th/db-get :team {:id (:default-team-id profile)}
{::db/remove-deleted false})))))))
(t/deftest blocked-chunk-does-not-stop-the-run
;; Chunks of one file: the blocked file takes down its own chunk and nothing
;; else, so the clean file of the next chunk is still deleted and the run
;; finishes. The next run retries the blocked file.
(let [profile (th/create-profile* 1)
blocked (create-deleted-file! profile 1 (ct/in-past "30m"))
clean (create-deleted-file! profile 2 (ct/in-past "20m"))
_ (block-file! blocked)
records (atom [])
_ (add-watch l/log-record ::capture
(fn [_ _ _ record] (swap! records conj record)))
result (try
(th/run-task! :objects-gc {:chunk-size 1})
(finally
(remove-watch l/log-record ::capture)))]
(t/testing "the clean file of the next chunk is deleted"
(t/is (nil? (find-file (:id clean)))))
(t/testing "the blocked file is still pending"
(t/is (some? (find-file (:id blocked)))))
(t/testing "the failed chunk is reported"
(t/is (some? (chunk-error records "file"))))
(t/testing "the run finishes"
(t/is (pos? (:processed result))))))
(defn- submitted-events
[audit-mock]
(->> (:call-args-list @audit-mock)
(map second)))
(defn- events-named
[audit-mock event-name]
(filter #(= event-name (:name %))
(submitted-events audit-mock)))
(t/deftest gc-emits-hard-delete-objects-for-teams
;; When the GC physically deletes a team, the projection must drop its row,
;; so the event carries the purged ids.
(with-mocks [audit-mock {:target 'app.loggers.audit/submit :return nil}]
(with-redefs [cf/flags (conj cf/flags :audit-log)]
(let [profile (th/create-profile* 1 {:is-active true})
team (th/create-team* 71 {:profile-id (:id profile)})]
(th/command! {::th/type :delete-team
::rpc/profile-id (:id profile)
:id (:id team)})
;; Run the queued cascade so the default project is marked deleted too,
;; then purge everything the way production does.
(th/run-pending-tasks!)
(th/reset-mock! audit-mock)
(th/run-task! :objects-gc {:skip-delay true})
(t/is (nil? (th/db-get :team {:id (:id team)} {::db/remove-deleted false})))
(let [events (filter #(contains? (:props %) :team-ids)
(events-named audit-mock "hard-delete-objects"))]
(t/is (= 1 (count events)))
(let [event (first events)]
(t/is (= "command" (:type event)))
(t/is (= [(:id team)] (get-in event [:props :team-ids])))
(t/is (= "objects-gc" (get-in event [:context :triggered-by])))))))))
(t/deftest gc-emits-hard-delete-objects-for-projects
(with-mocks [audit-mock {:target 'app.loggers.audit/submit :return nil}]
(with-redefs [cf/flags (conj cf/flags :audit-log)]
(let [profile (th/create-profile* 1 {:is-active true})
team (th/create-team* 72 {:profile-id (:id profile)})
project (th/create-project* 72 {:profile-id (:id profile)
:team-id (:id team)})]
(th/command! {::th/type :delete-project
::rpc/profile-id (:id profile)
:id (:id project)})
(th/run-pending-tasks!)
(th/reset-mock! audit-mock)
(th/run-task! :objects-gc {:skip-delay true})
(t/is (nil? (th/db-get :project {:id (:id project)} {::db/remove-deleted false})))
(let [events (filter #(contains? (:props %) :project-ids)
(events-named audit-mock "hard-delete-objects"))]
(t/is (= 1 (count events)))
(let [event (first events)]
(t/is (= "command" (:type event)))
(t/is (= [(:id project)] (get-in event [:props :project-ids])))
(t/is (= "objects-gc" (get-in event [:context :triggered-by])))))))))
(t/deftest gc-emits-hard-delete-objects-for-files
(with-mocks [audit-mock {:target 'app.loggers.audit/submit :return nil}]
(with-redefs [cf/flags (conj cf/flags :audit-log)]
(let [profile (th/create-profile* 1 {:is-active true})
team (th/create-team* 73 {:profile-id (:id profile)})
project (th/create-project* 73 {:profile-id (:id profile)
:team-id (:id team)})
file (th/create-file* 73 {:profile-id (:id profile)
:project-id (:id project)})]
(th/command! {::th/type :delete-file
::rpc/profile-id (:id profile)
:id (:id file)})
(th/run-pending-tasks!)
(th/reset-mock! audit-mock)
(th/run-task! :objects-gc {:skip-delay true})
(t/is (nil? (th/db-get :file {:id (:id file)} {::db/remove-deleted false})))
(let [events (filter #(contains? (:props %) :file-ids)
(events-named audit-mock "hard-delete-objects"))]
(t/is (= 1 (count events)))
(let [event (first events)]
(t/is (= "command" (:type event)))
(t/is (= [(:id file)] (get-in event [:props :file-ids])))
(t/is (= "objects-gc" (get-in event [:context :triggered-by])))))))))
(t/deftest gc-emits-no-event-without-audit-log-flag
;; The GC must stay silent when the audit log is off, even though the row is
;; still purged.
(with-mocks [audit-mock {:target 'app.loggers.audit/submit :return nil}]
(let [profile (th/create-profile* 1 {:is-active true})
team (th/create-team* 74 {:profile-id (:id profile)})]
(th/command! {::th/type :delete-team
::rpc/profile-id (:id profile)
:id (:id team)})
(th/run-pending-tasks!)
(th/reset-mock! audit-mock)
(th/run-task! :objects-gc {:skip-delay true})
(t/is (nil? (th/db-get :team {:id (:id team)} {::db/remove-deleted false})))
(t/is (empty? (:call-args-list @audit-mock))))))
(t/deftest gc-emits-events-only-for-committed-chunks
(with-mocks [audit-mock {:target 'app.loggers.audit/submit :return nil}]
(with-redefs [cf/flags (conj cf/flags :audit-log)]
(let [profile (th/create-profile* 1)
rolled-back (create-deleted-file! profile 1 (ct/in-past "30m"))
blocked (create-deleted-file! profile 2 (ct/in-past "20m"))
clean (create-deleted-file! profile 3 (ct/in-past "10m"))]
(block-file! blocked)
(th/reset-mock! audit-mock)
(let [result (th/run-task! :objects-gc {:chunk-size 2})
events (filter #(contains? (:props %) :file-ids)
(events-named audit-mock "hard-delete-objects"))]
(t/testing "the failed chunk keeps both files"
(t/is (some? (find-file (:id rolled-back))))
(t/is (some? (find-file (:id blocked)))))
(t/testing "the next chunk commits and reports only its deleted file"
(t/is (nil? (find-file (:id clean))))
(t/is (pos? (:processed result)))
(t/is (= 1 (count events)))
(t/is (= [(:id clean)] (get-in (first events) [:props :file-ids])))))))))