This commit is contained in:
Andrey Antukh
2026-02-03 15:57:52 +01:00
parent cf08bbc275
commit 1c7ed722f6
9 changed files with 311 additions and 163 deletions

View File

@@ -0,0 +1,46 @@
{% extends "app/templates/base.tmpl" %}
{% block title %}
Report: {{hint|abbreviate:150}} - {{id}} - Penpot Error Report (v3)
{% endblock %}
{% block content %}
<nav>
<div>[<a href="/dbg/error">⮜</a>]</div>
<div>[<a href="#head">head</a>]</div>
<!-- <div>[<a href="#props">props</a>]</div> -->
<div>[<a href="#context">context</a>]</div>
{% if report %}
<div>[<a href="#report">report</a>]</div>
{% endif %}
</nav>
<main>
<div class="table">
<div class="table-row multiline">
<div id="head" class="table-key">HEAD</div>
<div class="table-val">
<h1><span class="not-important">Hint:</span> <br/> {{hint}}</h1>
<h2><span class="not-important">Reported at:</span> <br/> {{created-at}}</h2>
<h2><span class="not-important">Report ID:</span> <br/> {{id}}</h2>
</div>
</div>
<div class="table-row multiline">
<div id="context" class="table-key">CONTEXT: </div>
<div class="table-val">
<pre>{{context}}</pre>
</div>
</div>
{% if report %}
<div class="table-row multiline">
<div id="report" class="table-key">REPORT:</div>
<div class="table-val">
<pre>{{report}}</pre>
</div>
</div>
{% endif %}
</div>
</main>
{% endblock %}

View File

@@ -227,6 +227,12 @@
(render-template-v3 [{:keys [content id created-at]}]
(-> (io/resource "app/templates/error-report.v3.tmpl")
(tmpl/render (-> content
(assoc :id id)
(assoc :created-at (ct/format-inst created-at :rfc1123))))))
(render-template-v4 [{:keys [content id created-at]}]
(-> (io/resource "app/templates/error-report.v4.tmpl")
(tmpl/render (-> content
(assoc :id id)
(assoc :created-at (ct/format-inst created-at :rfc1123))))))]
@@ -235,7 +241,8 @@
(let [result (case (:version report)
1 (render-template-v1 report)
2 (render-template-v2 report)
3 (render-template-v3 report))]
3 (render-template-v3 report)
4 (render-template-v4 report))]
{::yres/status 200
::yres/body result
::yres/headers {"content-type" "text/html; charset=utf-8"

View File

@@ -112,6 +112,8 @@
;; COLLECTOR API
;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;
(declare ^:private prepare-context-from-request)
;; Defines a service that collects the audit/activity log using
;; internal database. Later this audit log can be transferred to
;; an external storage and data cleared.
@@ -125,6 +127,8 @@
[::props {:optional true} [:map-of :keyword :any]]
[::context {:optional true} [:map-of :keyword :any]]
[::tracked-at {:optional true} ::ct/inst]
[::created-at {:optional true} ::ct/inst]
[::source {:optional true} ::sm/text]
[::webhooks/event? {:optional true} ::sm/boolean]
[::webhooks/batch-timeout {:optional true} ::ct/duration]
[::webhooks/batch-key {:optional true}
@@ -133,32 +137,8 @@
(def ^:private check-event
(sm/check-fn schema:event))
(defn- prepare-context-from-request
[request]
(let [client-event-origin (get-client-event-origin request)
client-version (get-client-version request)
client-user-agent (get-client-user-agent request)
session-id (get-external-session-id request)
token-id (::actoken/id request)]
(d/without-nils
{:external-session-id session-id
:access-token-id (some-> token-id str)
:client-event-origin client-event-origin
:client-user-agent client-user-agent
:client-version client-version
:version (:full cf/version)})))
(defn event-from-rpc-params
"Create a base event skeleton with pre-filled some important
data that can be extracted from RPC params object"
[params]
(let [context (some-> params meta ::http/request prepare-context-from-request)
event {::type "action"
::profile-id (or (::rpc/profile-id params) uuid/zero)
::ip-addr (::rpc/ip-addr params)}]
(cond-> event
(some? context)
(assoc ::context context))))
(def valid-event?
(sm/validator schema:event))
(defn prepare-event
[cfg mdata params result]
@@ -207,6 +187,33 @@
(::webhooks/event? resultm)
false)}))
(defn- prepare-context-from-request
[request]
(let [client-event-origin (get-client-event-origin request)
client-version (get-client-version request)
client-user-agent (get-client-user-agent request)
session-id (get-external-session-id request)
token-id (::actoken/id request)]
(d/without-nils
{:external-session-id session-id
:access-token-id (some-> token-id str)
:client-event-origin client-event-origin
:client-user-agent client-user-agent
:client-version client-version
:version (:full cf/version)})))
(defn event-from-rpc-params
"Create a base event skeleton with pre-filled some important
data that can be extracted from RPC params object"
[params]
(let [context (some-> params meta ::http/request prepare-context-from-request)
event {::type "action"
::profile-id (or (::rpc/profile-id params) uuid/zero)
::ip-addr (::rpc/ip-addr params)}]
(cond-> event
(some? context)
(assoc ::context context))))
(defn- event->params
[event]
(let [params {:id (uuid/next)
@@ -233,17 +240,16 @@
(defn- handle-event!
[cfg event]
(let [params (event->params event)
tnow (ct/now)]
(let [tnow (ct/now)
params (-> (event->params event)
(assoc :created-at tnow)
(update :tracked-at #(or % tnow)))]
(when (contains? cf/flags :audit-log)
;; NOTE: this operation may cause primary key conflicts on inserts
;; because of the timestamp precission (two concurrent requests), in
;; this case we just retry the operation.
(let [params (-> params
(assoc :created-at tnow)
(update :tracked-at #(or % tnow)))]
(append-audit-entry! cfg params)))
(append-audit-entry! cfg params))
(when (and (or (contains? cf/flags :telemetry)
(cf/get :telemetry-enabled))
@@ -254,8 +260,6 @@
;;
;; NOTE: this is only executed when general audit log is disabled
(let [params (-> params
(assoc :created-at tnow)
(update :tracked-at #(or % tnow))
(assoc :props {})
(assoc :context {}))]
(append-audit-entry! cfg params)))

View File

@@ -15,6 +15,7 @@
[app.config :as cf]
[app.db :as db]
[clojure.spec.alpha :as s]
[app.loggers.audit :as audit]
[integrant.core :as ig]
[promesa.exec :as px]
[promesa.exec.csp :as sp]))
@@ -28,69 +29,107 @@
(defonce enabled (atom true))
(defn- persist-on-database!
[pool id report]
[pool id version report]
(when-not (db/read-only? pool)
(db/insert! pool :server-error-report
{:id id
:version 3
:version version
:content (db/tjson report)})))
(defn- concurrent-exception?
[cause]
(or (instance? java.util.concurrent.CompletionException cause)
(instance? java.util.concurrent.ExecutionException cause)))
(defn record->report
[{:keys [::l/context ::l/message ::l/props ::l/logger ::l/level ::l/cause] :as record}]
(assert (l/valid-record? record) "expectd valid log record")
(if (or (instance? java.util.concurrent.CompletionException cause)
(instance? java.util.concurrent.ExecutionException cause))
(-> record
(assoc ::trace (ex/format-throwable cause :data? true :explain? false :header? false :summary? false))
(assoc ::l/cause (ex-cause cause))
(record->report))
(let [data (if (concurrent-exception? cause)
(ex-data (ex-cause cause))
(ex-data cause))
(let [data (ex-data cause)
ctx (-> context
(assoc :tenant (cf/get :tenant))
(assoc :host (cf/get :host))
(assoc :public-uri (str (cf/get :public-uri)))
(assoc :logger/name logger)
(assoc :logger/level level)
(dissoc :request/params :value :params :data))]
ctx (-> context
(assoc :tenant (cf/get :tenant))
(assoc :host (cf/get :host))
(assoc :public-uri (str (cf/get :public-uri)))
(assoc :version/backend (:full cf/version))
(assoc :logger/name logger)
(assoc :logger/level level)
(dissoc :request/params :value :params :data))]
(merge
{:context (-> (into (sorted-map) ctx)
(pp/pprint-str :length 50))
:props (pp/pprint-str props :length 50)
:hint (or (when-let [message (ex-message cause)]
(if-let [props-hint (:hint props)]
(str props-hint ": " message)
message))
@message)
:trace (or (::trace record)
(some-> cause (ex/format-throwable :data? true :explain? false :header? false :summary? false)))}
(merge
{:context (-> (into (sorted-map) ctx)
(pp/pprint-str :length 50))
:props (pp/pprint-str props :length 50)
:hint (or (when-let [message (ex-message cause)]
(if-let [props-hint (:hint props)]
(str props-hint ": " message)
message))
@message)
:trace (or (::trace record)
(some-> cause (ex/format-throwable :data? true :explain? false :header? false :summary? false)))}
(when-let [params (or (:request/params context) (:params context))]
{:params (pp/pprint-str params :length 20 :level 20)})
(when-let [params (or (:request/params context) (:params context))]
{:params (pp/pprint-str params :length 20 :level 20)})
(when-let [value (:value context)]
{:value (pp/pprint-str value :length 30 :level 13)})
(when-let [value (:value context)]
{:value (pp/pprint-str value :length 30 :level 13)})
(when-let [data (some-> data (dissoc ::s/problems ::s/value ::s/spec ::sm/explain :hint))]
{:data (pp/pprint-str data :length 30 :level 13)})
(when-let [data (some-> data (dissoc ::s/problems ::s/value ::s/spec ::sm/explain :hint))]
{:data (pp/pprint-str data :length 30 :level 13)})
(when-let [explain (ex/explain data :length 30 :level 13)]
{:explain explain})))))
(when-let [explain (ex/explain data :length 30 :level 13)]
{:explain explain}))))
(defn error-record?
[{:keys [::l/level]}]
(= :error level))
(defn- handle-event
(defn- handle-log-record
"Convert the log record into a report object and persist it on the database"
[{:keys [::db/pool]} {:keys [::l/id] :as record}]
(try
(let [uri (cf/get :public-uri)
report (-> record record->report d/without-nils)]
(l/debug :hint "registering error on database" :id id
:uri (str uri "/dbg/error/" id))
(l/dbg :hint "registering error on database"
:src "logging"
:id id
:uri (str uri "/dbg/error/" id))
(persist-on-database! pool id 3 report))
(catch Throwable cause
(l/warn :hint "unexpected exception on database error logger" :cause cause))))
(persist-on-database! pool id report))
(defn event->report
[{:keys [::audit/context ::audit/props ::audit/id ::audit/ip-addr] :as record}]
(let [context
(reduce-kv (fn [context k v]
(let [k' (keyword "frontend" (name k))]
(-> context
(dissoc k)
(assoc k' v))))
context
context)
context
(-> context
(assoc :backend/tenant (cf/get :tenant))
(assoc :backend/host (cf/get :host))
(assoc :backend/public-uri (str (cf/get :public-uri)))
(assoc :frontend/ip-addr ip-addr))]
{:context (-> (into (sorted-map) ctx)
(pp/pprint-str :length 50))
:props (pp/pprint-str props :length 50)
:hint (get props :hint)
:report (get props :report)}))
(defn- handle-audit-event
"Convert the log record into a report object and persist it on the database"
[{:keys [::db/pool]} {:keys [::audit/id] :as event}]
(try
(let [uri (cf/get :public-uri)
report (-> event event->report d/without-nils)]
(l/dbg :hint "registering error on database"
:id id
:src "audit-log"
:uri (str uri "/dbg/error/" id))
(persist-on-database! pool id 4 report))
(catch Throwable cause
(l/warn :hint "unexpected exception on database error logger" :cause cause))))
@@ -100,26 +139,48 @@
(defmethod ig/init-key ::reporter
[_ cfg]
(let [input (sp/chan :buf (sp/sliding-buffer 64)
:xf (filter error-record?))]
(add-watch l/log-record ::reporter #(sp/put! input %4))
(let [input (sp/chan :buf (sp/sliding-buffer 256))
thread (px/thread
{:name "penpot/reporter/database"}
(l/info :hint "initializing database error persistence")
(try
(loop []
(when-let [item (sp/take! input)]
(cond
(::l/id item)
(handle-log-record cfg item)
(px/thread {:name "penpot/database-reporter"}
(l/info :hint "initializing database error persistence")
(try
(loop []
(when-let [record (sp/take! input)]
(handle-event cfg record)
(recur)))
(catch InterruptedException _
(l/debug :hint "reporter interrupted"))
(catch Throwable cause
(l/error :hint "unexpected error" :cause cause))
(finally
(sp/close! input)
(remove-watch l/log-record ::reporter)
(l/info :hint "reporter terminated"))))))
(::audit/id item)
(handle-audit-event cfg item)
:else
(l/warn :hint "received unexpected item" :item item))
(recur)))
(catch InterruptedException _
(l/debug :hint "reporter interrupted"))
(catch Throwable cause
(l/error :hint "unexpected error" :cause cause))
(finally
(l/info :hint "reporter terminated"))))]
(add-watch l/log-record ::reporter
(fn [_ _ _ record]
(when (= :error (::l/level record))
(sp/put! input record))))
{::input input
::thread thread}))
(defmethod ig/halt-key! ::reporter
[_ thread]
(some-> thread px/interrupt!))
[_ {:keys [::input ::thread]}]
(remove-watch l/log-record ::reporter)
(sp/close! input)
(px/interrupt! thread))
(defn emit
"Emit an event/report into the database reporter"
[cfg event]
(when-let [{:keys [::input]} (get cfg ::reporter)]
(sp/put! input event)))

View File

@@ -11,7 +11,7 @@
[app.common.logging :as l]
[app.config :as cf]
[app.http.client :as http]
[app.loggers.database :as ldb]
[app.loggers.audit :as audit]
[app.util.json :as json]
[integrant.core :as ig]
[promesa.exec :as px]
@@ -50,7 +50,7 @@
(l/warn :hint "error on sending data"
:response (pr-str resp)))))
(defn record->report
(defn- record->report
[{:keys [::l/context ::l/id ::l/cause] :as record}]
(assert (l/valid-record? record) "expectd valid log record")
{:id id
@@ -64,14 +64,21 @@
:logger (::l/logger record)
:trace (ex/format-throwable cause :detail? false :header? false)})
(defn handle-event
(defn- handle-log-record
[cfg record]
(when @enabled
(try
(let [report (record->report record)]
(send-mattermost-notification! cfg report))
(catch Throwable cause
(l/warn :hint "unhandled error" :cause cause)))))
(try
(let [report (record->report record)]
(send-mattermost-notification! cfg report))
(catch Throwable cause
(l/warn :hint "unhandled error" :cause cause))))
(defn- handle-audit-event
[cfg record]
#_(try
(let [report (audit-event->report record)]
(send-mattermost-notification! cfg report))
(catch Throwable cause
(l/warn :hint "unhandled error" :cause cause))))
(defmethod ig/assert-key ::reporter
[_ params]
@@ -80,27 +87,43 @@
(defmethod ig/init-key ::reporter
[_ cfg]
(when-let [uri (cf/get :error-report-webhook)]
(px/thread
{:name "penpot/mattermost-reporter"
:virtual true}
(l/info :hint "initializing error reporter" :uri uri)
(let [input (sp/chan :buf (sp/sliding-buffer 128)
:xf (filter ldb/error-record?))]
(add-watch l/log-record ::reporter #(sp/put! input %4))
(try
(loop []
(when-let [msg (sp/take! input)]
(handle-event cfg msg)
(recur)))
(catch InterruptedException _
(l/debug :hint "reporter interrupted"))
(catch Throwable cause
(l/error :hint "unexpected error" :cause cause))
(finally
(sp/close! input)
(remove-watch l/log-record ::reporter)
(l/info :hint "reporter terminated")))))))
(let [input (sp/chan :buf (sp/sliding-buffer 256))
thread (px/thread
{:name "penpot/reporter/mattermost"}
(l/info :hint "initializing error reporter" :uri uri)
(try
(loop []
(when-let [item (sp/take! input)]
(when @enabled
(cond
(::l/id item)
(handle-log-record cfg item)
(::audit/id item)
(handle-audit-event cfg item)
:else
(l/warn :hint "received unexpected item" :item item)))
(recur)))
(catch InterruptedException _
(l/debug :hint "reporter interrupted"))
(catch Throwable cause
(l/error :hint "unexpected error" :cause cause))
(finally
(l/info :hint "reporter terminated"))))]
(add-watch l/log-record ::reporter
(fn [_ _ _ record]
(when (= :error (::l/level record))
(sp/put! input record))))
{::input input
::thread thread})))
(defmethod ig/halt-key! ::reporter
[_ thread]
[_ {:keys [::input ::thread]}]
(remove-watch l/log-record ::reporter)
(some-> input sp/close!)
(some-> thread px/interrupt!))

View File

@@ -337,7 +337,10 @@
::setup/props (ig/ref ::setup/props)
::email/blacklist (ig/ref ::email/blacklist)
::email/whitelist (ig/ref ::email/whitelist)}
::email/whitelist (ig/ref ::email/whitelist)
:app.loggers.database/reporter
(ig/ref :app.loggers.database/reporter)}
:app.rpc/management-methods
{::http.client/client (ig/ref ::http.client/client)

View File

@@ -16,6 +16,7 @@
[app.db :as db]
[app.http :as-alias http]
[app.loggers.audit :as-alias audit]
[app.loggers.database :as loggers.db]
[app.rpc :as-alias rpc]
[app.rpc.climit :as-alias climit]
[app.rpc.doc :as-alias doc]
@@ -36,42 +37,35 @@
:context])
(defn- event->row [event]
[(uuid/next)
(:name event)
(:source event)
(:type event)
(:timestamp event)
(:created-at event)
(:profile-id event)
(db/inet (:ip-addr event))
(db/tjson (:props event))
(db/tjson (d/without-nils (:context event)))])
[(::audit/id event)
(::audit/name event)
(::audit/source event)
(::audit/type event)
(::audit/tracked-at event)
(::audit/created-at event)
(::audit/profile-id event)
(db/inet (::audit/ip-addr event))
(db/tjson (::audit/props event))
(db/tjson (d/without-nils (::audit/context event)))])
(defn- adjust-timestamp
[{:keys [timestamp created-at] :as event}]
(let [margin (inst-ms (ct/diff timestamp created-at))]
[{:keys [::audit/tracked-at ::audit/created-at] :as event}]
(let [margin (inst-ms (ct/diff tracked-at created-at))]
(if (or (neg? margin)
(> margin 3600000))
;; If event is in future or lags more than 1 hour, we reasign
;; timestamp to the server creation date
;; tracked-at to the server creation date
(-> event
(assoc :timestamp created-at)
(update :context assoc :original-timestamp timestamp))
(assoc ::audit/tracked-at created-at)
(update ::audit/context assoc :original-tracked-at tracked-at))
event)))
(defn- excepition-event?
[{:keys [type name]}]
(defn- exception-event?
[{:keys [::audit/type ::audit/name] :as ev}]
(and (= "action" type)
(or (= "unhandled-exception" name)
(= "exception-page" name))))
(defn persist-report
[{:keys [::db/pool]} event]
)
(def ^:private xf:map-event-row
(comp
(map adjust-timestamp)
@@ -81,12 +75,18 @@
[{:keys [::rpc/request-at ::rpc/profile-id events] :as params}]
(let [request (-> params meta ::http/request)
ip-addr (inet/parse-request request)
xform (map (fn [event]
(-> event
(assoc :created-at request-at)
(assoc :profile-id profile-id)
(assoc :ip-addr ip-addr)
(assoc :source "frontend"))))]
{::audit/id (uuid/next)
::audit/type (:type event)
::audit/name (:name event)
::audit/props (:props event)
::audit/context (:context event)
::audit/profile-id profile-id
::audit/ip-addr ip-addr
::audit/source "frontend"
::audit/tracked-at (:timestamp event)
::audit/created-at request-at}))]
(sequence xform events)))
@@ -95,8 +95,9 @@
(let [events (get-events params)]
;; Look for error reports and save them on internal reports table
(->> (filter excepition-event? events)
(run! (partial persist-report cfg)))
(->> events
(sequence (filter exception-event?))
(run! (partial loggers.db/emit cfg)))
;; Process and save events
(when (seq events)
@@ -106,7 +107,7 @@
(def ^:private valid-event-types
#{"action" "identify"})
(def ^:private schema:event
(def ^:private schema:frontend-event
[:map {:title "Event"}
[:name
[:and {:gen/elements ["update-file", "get-profile"]}
@@ -118,12 +119,13 @@
[::sm/one-of {:format "string"} valid-event-types]]]
[:props
[:map-of :keyword ::sm/any]]
[:timestamp ::ct/inst]
[:context {:optional true}
[:map-of :keyword ::sm/any]]])
(def ^:private schema:push-audit-events
[:map {:title "push-audit-events"}
[:events [:vector schema:event]]])
[:events [:vector schema:frontend-event]]])
(sv/defmethod ::push-audit-events
{::climit/id :submit-audit-events/by-profile

View File

@@ -11,7 +11,8 @@
[selmer.filters :as sf]
[selmer.parser :as sp]))
;; (sp/cache-off!)
(sp/cache-off!)
(sf/add-filter! :abbreviate
(fn [s n]

View File

@@ -181,6 +181,7 @@
(fn [origin]
(let [mdata {:on-success on-file-created}
params {:project-id project-id}]
(assert (= 1 2) "foo")
(st/emit! (-> (dd/create-file (with-meta params mdata))
(with-meta {::ev/origin origin :has-files (> file-count 0)}))))))