Add performance and reporting improvements to migration script

This commit is contained in:
Andrey Antukh 2023-11-15 13:27:40 +01:00
parent 4c190e385e
commit 1457b7cf38
2 changed files with 165 additions and 171 deletions

View file

@ -45,6 +45,7 @@
[buddy.core.codecs :as bc] [buddy.core.codecs :as bc]
[cuerdas.core :as str] [cuerdas.core :as str]
[datoteka.io :as io] [datoteka.io :as io]
[promesa.exec :as px]
[promesa.exec.semaphore :as ps])) [promesa.exec.semaphore :as ps]))
;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;; ;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;
@ -53,6 +54,8 @@
(def ^:dynamic *system* nil) (def ^:dynamic *system* nil)
(def ^:dynamic *stats* nil) (def ^:dynamic *stats* nil)
(def ^:dynamic *file-stats* nil)
(def ^:dynamic *team-stats* nil)
(def ^:dynamic *semaphore* nil) (def ^:dynamic *semaphore* nil)
(def ^:dynamic *skip-on-error* true) (def ^:dynamic *skip-on-error* true)
@ -380,12 +383,10 @@
fdata fdata
(d/zip components positions))))] (d/zip components positions))))]
(when (some? *stats*)
(let [total (count components)] (let [total (count components)]
(swap! *stats* (fn [stats] (some-> *stats* (swap! update :processed/components (fnil + 0) total))
(-> stats (some-> *team-stats* (swap! update :processed/components (fnil + 0) total))
(update :processed/components (fnil + 0) total) (some-> *file-stats* (swap! assoc :processed/components total)))
(assoc :current/components total))))))
(-> file-data (-> file-data
(prepare-file-data libraries) (prepare-file-data libraries)
@ -575,8 +576,7 @@
cfsh/prepare-create-artboard-from-selection) cfsh/prepare-create-artboard-from-selection)
changes (pcb/concat-changes changes changes2)] changes (pcb/concat-changes changes changes2)]
(cp/process-changes (assoc-in fdata [:options :components-v2] true) ; Process component creation in v2 way (:redo-changes changes)))
(:redo-changes changes) false)))
(defn- migrate-graphics (defn- migrate-graphics
[fdata] [fdata]
@ -591,30 +591,48 @@
(grc/rect->points))] (grc/rect->points))]
(assoc media :points points))))) (assoc media :points points)))))
;; FIXME: think about what to do with existing media entries ??
grid (ctst/generate-shape-grid media position grid-gap)] grid (ctst/generate-shape-grid media position grid-gap)]
(when (some? *stats*)
(let [total (count media)] (let [total (count media)]
(swap! *stats* (fn [stats] (some-> *stats* (swap! update :processed/graphics (fnil + 0) total))
(-> stats (some-> *team-stats* (swap! update :processed/graphics (fnil + 0) total))
(update :processed/graphics (fnil + 0) total) (some-> *file-stats* (swap! assoc :processed/graphics total)))
(assoc :current/graphics total))))))
(->> (d/zip media grid) (let [factory (px/thread-factory :virtual true)
(reduce (fn [fdata [mobj position]] executor (px/fixed-executor :parallelism 10 :factory factory)
process (fn [mobj position]
(let [tp1 (dt/tpoint)]
(try (try
(process-media-object fdata page-id mobj position) (process-media-object fdata page-id mobj position)
(catch Throwable cause (catch Throwable cause
(l/warn :hint "unable to process file media object (skiping)" (l/wrn :hint "unable to process file media object (skiping)"
:file-id (str (:id fdata)) :file-id (str (:id fdata))
:id (str (:id mobj)) :id (str (:id mobj))
:cause cause) :cause cause)
(if-not *skip-on-error* (if-not *skip-on-error*
(throw cause) (throw cause)
fdata)))) fdata))
fdata))))) (finally
(l/trc :hint "graphic processed"
:file-id (str (:id fdata))
:media-id (str (:id mobj))
:elapsed (dt/format-duration (tp1)))))))
process (px/wrap-bindings process)]
(try
(->> (d/zip media grid)
(map (fn [[mobj position]]
(l/trc :hint "submit graphic processing" :file-id (str (:id fdata)) :id (str (:id mobj)))
(px/submit! executor (partial process mobj position))))
(reduce (fn [fdata promise]
(if-let [changes (deref promise)]
(cp/process-changes fdata changes false)
fdata))
fdata))
(finally
(.close ^java.lang.AutoCloseable executor)))))))
(defn- migrate-file-data (defn- migrate-file-data
[fdata libs] [fdata libs]
@ -665,7 +683,7 @@
(when validate? (when validate?
(let [errors (cfv/validate-file file libs)] (let [errors (cfv/validate-file file libs)]
(when (seq errors) (when (seq errors)
(l/err :hint "migrate:file:validation-error" (l/wrn :hint "migrate:file:validation-error"
:file-id (str (:id file)) :file-id (str (:id file))
:file-name (:name file) :file-name (:name file)
:errors errors)))) :errors errors))))
@ -674,43 +692,38 @@
(defn migrate-file! (defn migrate-file!
[system file-id & {:keys [validate?]}] [system file-id & {:keys [validate?]}]
(let [tpoint (dt/tpoint) (let [tpoint (dt/tpoint)
file-id (if (string? file-id) file-id (if (string? file-id)
(parse-uuid file-id) (parse-uuid file-id)
file-id)] file-id)]
(binding [*file-stats* (atom {})]
(try (try
(l/dbg :hint "migrate:file:start" :file-id (str file-id)) (l/dbg :hint "migrate:file:start" :file-id (str file-id))
(let [system (update system ::sto/storage media/configure-assets-storage)] (let [system (update system ::sto/storage media/configure-assets-storage)]
(db/tx-run! system (db/tx-run! system
(fn [{:keys [::db/conn] :as system}] (fn [{:keys [::db/conn] :as system}]
(binding [*system* system]
(fsnap/take-file-snapshot! system {:file-id file-id (fsnap/take-file-snapshot! system {:file-id file-id
:label "migration/components-v2"}) :label "migration/components-v2"})
(binding [*system* system]
(-> (db/get conn :file {:id file-id}) (-> (db/get conn :file {:id file-id})
(update :features db/decode-pgarray #{}) (update :features db/decode-pgarray #{})
(process-file :validate? validate?)))))) (process-file :validate? validate?))))))
(finally (finally
(let [elapsed (tpoint) (let [elapsed (tpoint)
stats (some-> *stats* deref)] components (get @*file-stats* :processed/components 0)
graphics (get @*file-stats* :processed/graphics 0)]
(l/dbg :hint "migrate:file:end" (l/dbg :hint "migrate:file:end"
:file-id (str file-id) :file-id (str file-id)
:components (:current/components stats 0) :graphics graphics
:graphics (:current/graphics stats 0) :components components
:elapsed (dt/format-duration elapsed)) :elapsed (dt/format-duration elapsed))
(when (some? *stats*) (some-> *stats* (swap! update :processed/files (fnil inc 0)))
(swap! *stats* (fn [stats] (some-> *team-stats* (swap! update :processed/files (fnil inc 0)))))))))
(let [elapsed (inst-ms elapsed)
completed (inc (get stats :processed/files 0))
total (+ (get stats :elapsed/total-by-file 0) elapsed)
avg (/ (double elapsed) completed)]
(-> stats
(update :elapsed/max-by-file (fnil max 0) elapsed)
(assoc :elapsed/avg-by-file avg)
(assoc :elapsed/total-by-file total)
(assoc :processed/files completed)))))))))))
(defn migrate-team! (defn migrate-team!
[system team-id & {:keys [validate?]}] [system team-id & {:keys [validate?]}]
@ -719,6 +732,7 @@
(parse-uuid team-id) (parse-uuid team-id)
team-id)] team-id)]
(l/dbg :hint "migrate:team:start" :team-id (dm/str team-id)) (l/dbg :hint "migrate:team:start" :team-id (dm/str team-id))
(binding [*team-stats* (atom {})]
(try (try
;; We execute this out of transaction because we want this ;; We execute this out of transaction because we want this
;; change to be visible to all other sessions before starting ;; change to be visible to all other sessions before starting
@ -748,7 +762,6 @@
(map :id))] (map :id))]
(run! #(migrate-file! system % :validate? validate?) rows) (run! #(migrate-file! system % :validate? validate?) rows)
(some-> *stats* (swap! assoc :current/files (count rows)))
(let [features (-> features (let [features (-> features
(disj "ephimeral/v2-migration") (disj "ephimeral/v2-migration")
@ -760,19 +773,8 @@
{:id team-id}))))))) {:id team-id})))))))
(finally (finally
(some-> *semaphore* ps/release!) (some-> *semaphore* ps/release!)
(let [elapsed (tpoint) (let [elapsed (tpoint)]
stats (some-> *stats* deref)] (some-> *stats* (swap! update :processed/teams (fnil inc 0)))
(when (some? *stats*)
(swap! *stats* (fn [stats]
(let [elapsed (inst-ms elapsed)
completed (inc (get stats :processed/teams 0))
total (+ (get stats :elapsed/total-by-team 0) elapsed)
avg (/ (double elapsed) completed)]
(-> stats
(update :elapsed/max-by-team (fnil max 0) elapsed)
(assoc :elapsed/avg-by-team avg)
(assoc :elapsed/total-by-team total)
(assoc :processed/teams completed))))))
;; We execute this out of transaction because we want this ;; We execute this out of transaction because we want this
;; change to be visible to all other sessions before starting ;; change to be visible to all other sessions before starting
@ -782,9 +784,14 @@
" WHERE id = ?")] " WHERE id = ?")]
(db/exec-one! system [sql team-id])) (db/exec-one! system [sql team-id]))
(let [components (get @*team-stats* :processed/components 0)
graphics (get @*team-stats* :processed/graphics 0)
files (get @*team-stats* :processed/files 0)]
(l/dbg :hint "migrate:team:end" (l/dbg :hint "migrate:team:end"
:team-id (dm/str team-id) :team-id (dm/str team-id)
:files (:current/files stats 0) :files files
:elapsed (dt/format-duration elapsed))))))) :components components
:graphics graphics
:elapsed (dt/format-duration elapsed)))))))))

View file

@ -21,17 +21,9 @@
(defn- print-stats! (defn- print-stats!
[stats] [stats]
(let [stats (-> stats
(d/update-when :elapsed/max-by-team (comp dt/format-duration dt/duration int))
(d/update-when :elapsed/avg-by-team (comp dt/format-duration dt/duration int))
(d/update-when :elapsed/total-by-team (comp dt/format-duration dt/duration int))
(d/update-when :elapsed/max-by-file (comp dt/format-duration dt/duration int))
(d/update-when :elapsed/avg-by-file (comp dt/format-duration dt/duration int))
(d/update-when :elapsed/total-by-file (comp dt/format-duration dt/duration int))
)]
(->> stats (->> stats
(into (sorted-map)) (into (sorted-map))
(pp/pprint)))) (pp/pprint)))
(defn- report-progress-files (defn- report-progress-files
[tpoint] [tpoint]
@ -42,7 +34,7 @@
completed (:processed/files newv) completed (:processed/files newv)
progress (/ (* completed 100.0) total) progress (/ (* completed 100.0) total)
elapsed (tpoint)] elapsed (tpoint)]
(l/trc :hint "progress" (l/dbg :hint "progress"
:completed (:processed/files newv) :completed (:processed/files newv)
:total (:total/files newv) :total (:total/files newv)
:progress (str (int progress) "%") :progress (str (int progress) "%")
@ -57,8 +49,11 @@
completed (:processed/teams newv) completed (:processed/teams newv)
progress (/ (* completed 100.0) total) progress (/ (* completed 100.0) total)
elapsed (tpoint)] elapsed (tpoint)]
(l/trc :hint "progress" (l/dbg :hint "progress"
:completed (:processed/teams newv) :completed-teams (:processed/teams newv)
:completed-files (:processed/files newv)
:completed-graphics (:processed/graphics newv)
:completed-components (:processed/components newv)
:progress (str (int progress) "%") :progress (str (int progress) "%")
:elapsed (dt/format-duration elapsed)))))) :elapsed (dt/format-duration elapsed))))))
@ -88,36 +83,35 @@
(:count res))) (:count res)))
(defn migrate-file! (defn migrate-file!
[system file-id & {:keys [rollback] :or {rollback true}}] [system file-id & {:keys [rollback?] :or {rollback? true}}]
(l/dbg :hint "migrate:start") (l/dbg :hint "migrate:start")
(let [tpoint (dt/tpoint)] (let [tpoint (dt/tpoint)]
(try (try
(binding [feat/*stats* (atom {})] (binding [feat/*stats* (atom {})]
(-> (assoc system ::db/rollback rollback) (-> (assoc system ::db/rollback rollback?)
(feat/migrate-file! file-id)) (feat/migrate-file! file-id))
(-> (deref feat/*stats*) (-> (deref feat/*stats*)
(assoc :elapsed (dt/format-duration (tpoint))) (assoc :elapsed (dt/format-duration (tpoint)))))
(dissoc :current/graphics)
(dissoc :current/components)
(dissoc :current/files)))
(catch Throwable cause (catch Throwable cause
(l/dbg :hint "migrate:error" :cause cause)) (l/wrn :hint "migrate:error" :cause cause))
(finally (finally
(let [elapsed (dt/format-duration (tpoint))] (let [elapsed (dt/format-duration (tpoint))]
(l/dbg :hint "migrate:end" :elapsed elapsed)))))) (l/dbg :hint "migrate:end" :elapsed elapsed))))))
(defn migrate-files! (defn migrate-files!
[{:keys [::db/pool] :as system} & {:keys [chunk-size max-jobs max-items start-at preset rollback skip-on-error validate] [{:keys [::db/pool] :as system}
& {:keys [chunk-size max-jobs max-items start-at preset rollback? skip-on-error validate?]
:or {chunk-size 10 :or {chunk-size 10
skip-on-error true skip-on-error true
max-jobs 10 max-jobs 10
max-items Long/MAX_VALUE max-items Long/MAX_VALUE
preset :shutdown-on-failure preset :shutdown-on-failure
rollback true rollback? true
validate false}}] validate? false}}]
(letfn [(get-chunk [cursor] (letfn [(get-chunk [cursor]
(let [sql (str/concat (let [sql (str/concat
"SELECT id, created_at FROM file " "SELECT id, created_at FROM file "
@ -151,17 +145,14 @@
(run! (fn [file-id] (run! (fn [file-id]
(ps/acquire! feat/*semaphore*) (ps/acquire! feat/*semaphore*)
(px/submit! scope (fn [] (px/submit! scope (fn []
(-> (assoc system ::db/rollback rollback) (-> (assoc system ::db/rollback rollback?)
(feat/migrate-file! file-id :validate? validate))))) (feat/migrate-file! file-id :validate? validate?)))))
(get-candidates)) (get-candidates))
(p/await! scope)) (p/await! scope))
(-> (deref feat/*stats*) (-> (deref feat/*stats*)
(assoc :elapsed (dt/format-duration (tpoint))) (assoc :elapsed (dt/format-duration (tpoint))))
(dissoc :current/graphics)
(dissoc :current/components)
(dissoc :current/files))
(catch Throwable cause (catch Throwable cause
(l/dbg :hint "migrate:error" :cause cause)) (l/dbg :hint "migrate:error" :cause cause))
@ -172,8 +163,8 @@
(defn migrate-team! (defn migrate-team!
[{:keys [::db/pool] :as system} team-id [{:keys [::db/pool] :as system} team-id
& {:keys [rollback skip-on-error validate] & {:keys [rollback? skip-on-error validate?]
:or {rollback true skip-on-error true validate false}}] :or {rollback? true skip-on-error true validate? false}}]
(l/dbg :hint "migrate:start") (l/dbg :hint "migrate:start")
(let [total (get-total-files pool :team-id team-id) (let [total (get-total-files pool :team-id team-id)
@ -185,15 +176,13 @@
(try (try
(binding [feat/*stats* stats (binding [feat/*stats* stats
feat/*skip-on-error* skip-on-error] feat/*skip-on-error* skip-on-error]
(-> (assoc system ::db/rollback rollback) (-> (assoc system ::db/rollback rollback?)
(feat/migrate-team! team-id :validate? validate)) (feat/migrate-team! team-id :validate? validate?))
(print-stats! (print-stats!
(-> (deref feat/*stats*) (-> (deref feat/*stats*)
(dissoc :total/files) (dissoc :total/files)
(dissoc :current/graphics) (assoc :elapsed (dt/format-duration (tpoint))))))
(dissoc :current/components)
(dissoc :current/files))))
(catch Throwable cause (catch Throwable cause
(l/dbg :hint "migrate:error" :cause cause)) (l/dbg :hint "migrate:error" :cause cause))
@ -204,14 +193,14 @@
(defn migrate-teams! (defn migrate-teams!
[{:keys [::db/pool] :as system} [{:keys [::db/pool] :as system}
& {:keys [chunk-size max-jobs max-items start-at rollback preset skip-on-error max-time validate] & {:keys [chunk-size max-jobs max-items start-at rollback? preset skip-on-error max-time validate?]
:or {chunk-size 10000 :or {chunk-size 10000
rollback true validate? false
rollback? true
skip-on-error true skip-on-error true
preset :shutdown-on-failure preset :shutdown-on-failure
max-jobs Integer/MAX_VALUE max-jobs Integer/MAX_VALUE
max-items Long/MAX_VALUE max-items Long/MAX_VALUE}}]
validate false}}]
(letfn [(get-chunk [cursor] (letfn [(get-chunk [cursor]
(let [sql (str/concat (let [sql (str/concat
@ -233,8 +222,8 @@
(migrate-team [team-id] (migrate-team [team-id]
(try (try
(-> (assoc system ::db/rollback rollback) (-> (assoc system ::db/rollback rollback?)
(feat/migrate-team! team-id :validate? validate)) (feat/migrate-team! team-id :validate? validate?))
(catch Throwable cause (catch Throwable cause
(l/err :hint "unexpected error on processing team" :team-id (dm/str team-id) :cause cause)))) (l/err :hint "unexpected error on processing team" :team-id (dm/str team-id) :cause cause))))
@ -242,7 +231,7 @@
(ps/acquire! feat/*semaphore*) (ps/acquire! feat/*semaphore*)
(let [ts (tpoint)] (let [ts (tpoint)]
(if (and mtime (neg? (compare mtime ts))) (if (and mtime (neg? (compare mtime ts)))
(l/trc :hint "max time constraint reached" :elapsed (dt/format-duration ts)) (l/inf :hint "max time constraint reached" :elapsed (dt/format-duration ts))
(px/submit! scope (partial migrate-team team-id)))))] (px/submit! scope (partial migrate-team team-id)))))]
(l/dbg :hint "migrate:start") (l/dbg :hint "migrate:start")
@ -270,10 +259,8 @@
(print-stats! (print-stats!
(-> (deref feat/*stats*) (-> (deref feat/*stats*)
(dissoc :total/teams) (assoc :elapsed/total (dt/format-duration (tpoint)))
(dissoc :current/graphics) (dissoc :total/teams)))
(dissoc :current/components)
(dissoc :current/files)))
(catch Throwable cause (catch Throwable cause
(l/dbg :hint "migrate:error" :cause cause)) (l/dbg :hint "migrate:error" :cause cause))