Add logging/tracing improvements to binfile rpc impl

This commit is contained in:
Andrey Antukh 2023-11-24 07:51:02 +01:00
parent 852e7472b7
commit 3eb1bb6487

View file

@ -518,24 +518,25 @@
(vswap! *state* assoc :sids []) (vswap! *state* assoc :sids [])
(doseq [file-id (-> *state* deref :files)] (doseq [file-id (-> *state* deref :files)]
(let [detach? (and (not embed-assets?) (not include-libraries?)) (let [detach? (and (not embed-assets?) (not include-libraries?))
thumbnails (get-file-thumbnails cfg file-id) thumbnails (get-file-thumbnails cfg file-id)
file (cond-> (get-file cfg file-id) file (cond-> (get-file cfg file-id)
detach? detach?
(-> (ctf/detach-external-references file-id) (-> (ctf/detach-external-references file-id)
(dissoc :libraries)) (dissoc :libraries))
embed-assets? embed-assets?
(update :data embed-file-assets cfg file-id) (update :data embed-file-assets cfg file-id)
:always :always
(assoc :thumbnails thumbnails)) (assoc :thumbnails thumbnails))
media (get-file-media cfg file)] media (get-file-media cfg file)]
(l/dbg :hint "write penpot file" (l/dbg :hint "write penpot file"
:id file-id :id (str file-id)
:name (:name file) :name (:name file)
:thumbnails (count thumbnails)
:features (:features file) :features (:features file)
:media (count media) :media (count media)
::l/sync? true) ::l/sync? true)
@ -543,6 +544,9 @@
(doseq [item media] (doseq [item media]
(l/dbg :hint "write penpot file media object" :id (:id item) ::l/sync? true)) (l/dbg :hint "write penpot file media object" :id (:id item) ::l/sync? true))
(doseq [item thumbnails]
(l/dbg :hint "write penpot file object thumbnail" :media-id (str (:media-id item)) ::l/sync? true))
(doto output (doto output
(write-obj! file) (write-obj! file)
(write-obj! media)) (write-obj! media))
@ -572,7 +576,8 @@
(doseq [id sids] (doseq [id sids]
(let [{:keys [size] :as obj} (sto/get-object storage id)] (let [{:keys [size] :as obj} (sto/get-object storage id)]
(l/dbg :hint "write sobject" :id id ::l/sync? true) (l/dbg :hint "write sobject" :id (str id) ::l/sync? true)
(doto output (doto output
(write-uuid! id) (write-uuid! id)
(write-obj! (meta obj))) (write-obj! (meta obj)))
@ -677,7 +682,10 @@
(defmethod read-section :v1/metadata (defmethod read-section :v1/metadata
[{:keys [::input]}] [{:keys [::input]}]
(let [{:keys [version files]} (read-obj! input)] (let [{:keys [version files]} (read-obj! input)]
(l/dbg :hint "metadata readed" :version (:full version) :files files ::l/sync? true) (l/dbg :hint "metadata readed"
:version (:full version)
:files (mapv str files)
::l/sync? true)
(vswap! *state* update :index update-index files) (vswap! *state* update :index update-index files)
(vswap! *state* assoc :version version :files files))) (vswap! *state* assoc :version version :files files)))
@ -692,33 +700,29 @@
(not (contains? cfeat/*previous* "fdata/pointer-map"))) (not (contains? cfeat/*previous* "fdata/pointer-map")))
(features.fdata/enable-pointer-map))) (features.fdata/enable-pointer-map)))
(defn- update-thumbnail (defn- get-remaped-thumbnails
[thumbnail file-id] [thumbnails file-id]
(let [thumbnail (assoc thumbnail :file-id file-id) (mapv (fn [thumbnail]
object-id (:object-id thumbnail) (-> thumbnail
object-id (str/replace-first object-id #"^(.*?)/" (str file-id "/")) (assoc :file-id file-id)
thumbnail (assoc thumbnail :object-id object-id)] (update :object-id #(str/replace-first % #"^(.*?)/" (str file-id "/")))))
thumbnails))
thumbnail))
(defn- update-file-thumbnails
[file file-id]
(let [thumbnails (:thumbnails file)]
(mapv #(update-thumbnail % file-id) thumbnails)))
(defmethod read-section :v1/files (defmethod read-section :v1/files
[{:keys [::db/conn ::input ::project-id ::enabled-features ::timestamp ::overwrite?]}] [{:keys [::db/conn ::input ::project-id ::enabled-features ::timestamp ::overwrite?]}]
(doseq [expected-file-id (-> *state* deref :files)] (doseq [expected-file-id (-> *state* deref :files)]
(let [file (read-obj! input) (let [file (read-obj! input)
media' (read-obj! input) media (read-obj! input)
file-id (:id file) file-id (:id file)
file-id' (lookup-index file-id) file-id' (lookup-index file-id)
features (-> enabled-features thumbnails (:thumbnails file)
(set/difference cfeat/frontend-only-features)
(set/union (cfeat/check-supported-features! (:features file))))] features (-> enabled-features
(set/difference cfeat/frontend-only-features)
(set/union (cfeat/check-supported-features! (:features file))))]
;; All features that are enabled and requires explicit migration ;; All features that are enabled and requires explicit migration
;; are added to the state for a posterior migration step ;; are added to the state for a posterior migration step
@ -734,28 +738,32 @@
:expected-id expected-file-id :expected-id expected-file-id
:hint "the penpot file seems corrupt, found unexpected uuid (file-id)")) :hint "the penpot file seems corrupt, found unexpected uuid (file-id)"))
(when (contains? file :thumbnails) (l/dbg :hint "processing file"
(let [updated-thumbnails (update-file-thumbnails file file-id')] :id (str file-id)
(vswap! *state* update :thumbnails (fnil into []) updated-thumbnails) :features (:features file)
(l/dbg :hint "thumbnails updated" :thumbnails (count updated-thumbnails) ::l/sync? true))) :version (-> file :data :version)
:media (count media)
:thumbnails (count thumbnails)
::l/sync? true)
;; Update index using with media (when (seq thumbnails)
(l/dbg :hint "update index with media" ::l/sync? true) (let [thumbnails (get-remaped-thumbnails thumbnails file-id')]
(vswap! *state* update :index update-index (map :id media')) (l/dbg :hint "updated index with thumbnails" :total (count thumbnails) ::l/sync? true)
(vswap! *state* update :thumbnails (fnil into []) thumbnails)))
;; Store file media for later insertion (when (seq media)
(l/dbg :hint "update media references" ::l/sync? true) ;; Update index with media
(vswap! *state* update :media into (map #(update % :id lookup-index)) media') (l/dbg :hint "update index with media" :total (count media) ::l/sync? true)
(vswap! *state* update :index update-index (map :id media))
;; Store file media for later insertion
(l/dbg :hint "update media references" ::l/sync? true)
(vswap! *state* update :media into (map #(update % :id lookup-index)) media))
(binding [cfeat/*current* features (binding [cfeat/*current* features
cfeat/*previous* (:features file) cfeat/*previous* (:features file)
pmap/*tracked* (atom {})] pmap/*tracked* (atom {})]
(l/dbg :hint "processing file"
:id file-id
:features (:features file)
:version (-> file :data :version)
::l/sync? true)
(let [params (-> file (let [params (-> file
(assoc :id file-id') (assoc :id file-id')
@ -798,7 +806,7 @@
(update :features #(db/create-array conn "text" %)) (update :features #(db/create-array conn "text" %))
(update :data blob/encode))] (update :data blob/encode))]
(l/dbg :hint "create file" :id file-id' ::l/sync? true) (l/dbg :hint "create file" :id (str file-id') ::l/sync? true)
(if overwrite? (if overwrite?
(create-or-update-file! conn params) (create-or-update-file! conn params)
@ -871,9 +879,11 @@
sobject (sto/put-object! storage params)] sobject (sto/put-object! storage params)]
(l/dbg :hint "persisted storage object" (l/dbg :hint "persisted storage object"
:id (str id) :old-id (str id)
:new-id (str (:id sobject)) :new-id (str (:id sobject))
:is-thumbnail (boolean (thumb? id))
::l/sync? true) ::l/sync? true)
(vswap! *state* update :index assoc id (:id sobject))))) (vswap! *state* update :index assoc id (:id sobject)))))
(doseq [item (:media @*state*)] (doseq [item (:media @*state*)]
@ -893,13 +903,15 @@
{:on-conflict-do-nothing overwrite?})))) {:on-conflict-do-nothing overwrite?}))))
(doseq [item (:thumbnails @*state*)] (doseq [item (:thumbnails @*state*)]
(l/dbg :hint "inserting file object thumbnail" (let [item (update item :media-id lookup-index)]
:file-id (:file-id item) (l/dbg :hint "inserting file object thumbnail"
:object-id (:object-id item) :file-id (str (:file-id item))
::l/sync? true) :media-id (str (:media-id item))
(db/insert! conn :file-tagged-object-thumbnail :object-id (:object-id item)
(update item :media-id lookup-index) ::l/sync? true)
{:on-conflict-do-nothing overwrite?})))) (db/insert! conn :file-tagged-object-thumbnail
(update item :media-id lookup-index)
{:on-conflict-do-nothing overwrite?})))))
(defn- lookup-index (defn- lookup-index
[id] [id]
@ -994,7 +1006,7 @@
ab (volatile! false) ab (volatile! false)
cs (volatile! nil)] cs (volatile! nil)]
(try (try
(l/info :hint "start exportation" :export-id id) (l/info :hint "start exportation" :export-id (str id))
(pu/with-open [output (io/output-stream output)] (pu/with-open [output (io/output-stream output)]
(binding [*position* (atom 0)] (binding [*position* (atom 0)]
(write-export! (assoc cfg ::output output)))) (write-export! (assoc cfg ::output output))))
@ -1010,7 +1022,7 @@
(throw cause)) (throw cause))
(finally (finally
(l/info :hint "exportation finished" :export-id id (l/info :hint "exportation finished" :export-id (str id)
:elapsed (str (inst-ms (tp)) "ms") :elapsed (str (inst-ms (tp)) "ms")
:aborted @ab :aborted @ab
:cause @cs))))) :cause @cs)))))
@ -1027,7 +1039,7 @@
(let [id (uuid/next) (let [id (uuid/next)
tp (dt/tpoint) tp (dt/tpoint)
cs (volatile! nil)] cs (volatile! nil)]
(l/info :hint "import: started" :import-id id) (l/info :hint "import: started" :id (str id))
(try (try
(binding [*position* (atom 0)] (binding [*position* (atom 0)]
(pu/with-open [input (io/input-stream input)] (pu/with-open [input (io/input-stream input)]
@ -1039,7 +1051,7 @@
(finally (finally
(l/info :hint "import: terminated" (l/info :hint "import: terminated"
:import-id id :id (str id)
:elapsed (dt/format-duration (tp)) :elapsed (dt/format-duration (tp))
:error? (some? @cs)))))) :error? (some? @cs))))))