Merge pull request #3199 from CSCfi/extended-logging2

Extended logging 2

docs/configuration.md

@@ -183,13 +183,19 @@ REMS uses [Logback](https://logback.qos.ch/) for logging. By default everything
 
 ### Extended Logging
 
-The config option `:enable-extended-logging` can be toggled to additionally log the content of entity mutations.
+The config option `:enable-extended-logging` can be toggled to additionally log the content of entity mutations. These logs enable auditors to unequivocally determine the state of a given entity at a given time. Which may aid with various regulatory requirements.
 
-These logs enable auditors to unequivocally determine the state of a given entity at a given time. Which may aid with various regulatory requirements.
+The extended logging is at `INFO` level and the log messages are prefixed with `> params:`. Use these together with the regular request logging to know the API URL, user etc.
 
-Logging is at `INFO` level and the log messages are prefixed with `extended-logging (:uri request)` e.g. `extended-logging /api/forms/edit`.
+For example, the third line of this log is the extended logging (actual parameters sent by the user).
+```
+2023-10-16 19:54:40,626 [6b31f9b67c20 rqc:1 owner lGpEJ6Ke] INFO  rems.middleware - req > :post /api/resources/create
+2023-10-16 19:54:40,631 [6b31f9b67c20 rqc:1 owner lGpEJ6Ke] INFO  rems.middleware - > :post /api/resources/create lang: :en user: {:userid owner, :name Owner, :email owner@example.com}  roles: #{:logged-in :owner}
+2023-10-16 19:54:40,637 [6b31f9b67c20 rqc:1 owner lGpEJ6Ke] INFO  rems.api.resources - > params: {:licenses [], :organization #:organization{:id nbn}, :resid my-res-test}
+2023-10-16 19:54:40,640 [6b31f9b67c20 rqc:1 owner lGpEJ6Ke] INFO  rems.middleware - req < :post /api/resources/create 200 14ms
+```
 
-Logging occurs before the mutation is persisted. As such, the logged information is only authoritative about the state of the respective entity iff the request was successful.
+Extended logging occurs before the business logic is executed, i.e. mutation is persisted. As such, the logged information is only authoritative about the state of the respective entity if and only if the request was successful.
 
 ## Application expiration scheduler
 

project.clj

@@ -125,7 +125,8 @@
                                 [ring/ring-mock "0.4.0" :exclusions [cheshire]]
                                 [se.haleby/stub-http "0.2.14"]
                                 [com.icegreen/greenmail "1.6.12"]
-                                [macroz/tangle "0.2.2"]]
+                                [macroz/tangle "0.2.2"]
+                                [peridot "0.5.4"]]
 
                  :plugins [[lein-ancient "0.6.15"]]
 

src/clj/rems/api/applications.clj

@@ -9,7 +9,7 @@
             [rems.service.command :as command]
             [rems.service.licenses :as licenses]
             [rems.service.todos :as todos]
-            [rems.api.util :as api-util] ; required for route :roles
+            [rems.api.util :as api-util :refer [extended-logging]] ; required for route :roles
             [rems.application.commands :as commands]
             [rems.application.search :as search]
             [rems.auth.auth :as auth]
@@ -110,12 +110,13 @@
 
 (defmacro command-endpoint [command schema & [additional-doc]]
   (let [path (str "/" (name command))]
-    `(POST ~path []
+    `(POST ~path ~'request
        :summary ~(str "Submit a `" (name command) "` command for an application. " additional-doc)
        :roles #{:logged-in}
-       :body [request# ~schema]
+       :body [body# ~schema]
        :return schema/SuccessResponse
-       (ok (api-command ~command request#)))))
+       (extended-logging ~'request)
+       (ok (api-command ~command body#)))))
 
 (defn accept-invitation [invitation-token]
   (if-let [application-id (applications/get-application-by-invitation-token invitation-token)]
@@ -179,18 +180,20 @@
             true (sort-by last-activity >)
             limit (take limit))))
 
-    (POST "/create" []
+    (POST "/create" request
       :summary "Create a new application"
       :roles #{:logged-in}
-      :body [request CreateApplicationCommand]
+      :body [command CreateApplicationCommand]
       :return CreateApplicationResponse
-      (ok (api-command :application.command/create request)))
+      (extended-logging request)
+      (ok (api-command :application.command/create command)))
 
-    (POST "/copy-as-new" []
+    (POST "/copy-as-new" request
       :summary "Create a new application as a copy of an existing application."
       :roles #{:logged-in}
       :body [request commands/CopyAsNewCommand]
       :return CopyAsNewResponse
+      (extended-logging request)
       (ok (api-command :application.command/copy-as-new request)))
 
     (GET "/reviewers" []
@@ -229,26 +232,29 @@
         (attachment/download attachment)
         (api-util/not-found-json-response)))
 
-    (POST "/add-attachment" []
+    (POST "/add-attachment" request
       :summary "Add an attachment file related to an application"
       :roles #{:logged-in}
       :multipart-params [file :- schema/FileUpload]
       :query-params [application-id :- (describe s/Int "application id")]
       :return SaveAttachmentResponse
+      (extended-logging request)
       (ok (attachment/add-application-attachment (getx-user-id) application-id file)))
 
-    (POST "/accept-invitation" []
+    (POST "/accept-invitation" request
       :summary "Accept an invitation by token"
       :roles #{:logged-in}
       :query-params [invitation-token :- (describe s/Str "invitation token")]
       :return AcceptInvitationResult
+      (extended-logging request)
       (ok (accept-invitation invitation-token)))
 
-    (POST "/validate" []
+    (POST "/validate" request
       :summary "Validate the form, like in save, but nothing is saved. NB: At the moment, both errors and validations are identical, but this may not always be so."
       :roles #{:logged-in}
       :body [request ValidateRequest]
       :return schema/SuccessResponse
+      (extended-logging request) ; this is for completeness, nothing should be saved
       (ok (validate-application request)))
 
     (GET "/commands" []

src/clj/rems/api/blacklist.clj

@@ -4,7 +4,7 @@
             [rems.api.schema :as schema]
             [rems.service.command :as command]
             [rems.service.blacklist :as blacklist]
-            [rems.api.util :refer [unprocessable-entity-json-response]] ; required for route :roles
+            [rems.api.util :refer [extended-logging unprocessable-entity-json-response]] ; required for route :roles
             [rems.application.rejecter-bot :as rejecter-bot]
             [rems.common.roles :refer [+admin-read-roles+]]
             [rems.db.resource :as resource]
@@ -56,11 +56,12 @@
 
     ;; TODO write access to blacklist for organization-owner
 
-    (POST "/add" []
+    (POST "/add" request
       :summary "Add a blacklist entry"
       :roles #{:owner :handler}
       :body [command BlacklistCommand]
       :return schema/SuccessResponse
+      (extended-logging request)
       (let [userid (user-mappings/find-userid (getx-in command [:blacklist/user :userid]))
             command (assoc-in command [:blacklist/user :userid] userid)]
         (or (user-not-found-error command)
@@ -73,11 +74,12 @@
                                  {:cmd cmd :result result}))))
                 (ok {:success true})))))
 
-    (POST "/remove" []
+    (POST "/remove" request
       :summary "Remove a blacklist entry"
       :roles #{:owner :handler}
       :body [command BlacklistCommand]
       :return schema/SuccessResponse
+      (extended-logging request)
       (let [userid (user-mappings/find-userid (getx-in command [:blacklist/user :userid]))
             command (assoc-in command [:blacklist/user :userid] userid)]
         (or (user-not-found-error command)

src/clj/rems/api/catalogue_items.clj

@@ -80,13 +80,14 @@
                                                      :expand-names? (str/includes? (or expand "") "names")
                                                      :archived archived}))))
 
-    (POST "/:item-id/change-form" []
+    (POST "/:item-id/change-form" request
       :summary "Change catalogue item form. Creates a copy and ends the old."
       :roles +admin-write-roles+
       :path-params [item-id :- (describe s/Int "catalogue item")]
       :body [command ChangeFormCommand]
       :responses {200 {:schema ChangeFormResponse}
                   404 {:schema s/Any :description "Not found"}}
+      (extended-logging request)
       (if-let [it (catalogue/get-localized-catalogue-item item-id)]
         (ok (catalogue/change-form! it (:form command)))
         (not-found-json-response)))
@@ -120,16 +121,18 @@
         (not-found-json-response)
         (ok (catalogue/edit-catalogue-item! command))))
 
-    (PUT "/archived" []
+    (PUT "/archived" request
       :summary "Archive or unarchive catalogue item"
       :roles +admin-write-roles+
       :body [command schema/ArchivedCommand]
       :return schema/SuccessResponse
+      (extended-logging request)
       (ok (catalogue/set-catalogue-item-archived! command)))
 
-    (PUT "/enabled" []
+    (PUT "/enabled" request
       :summary "Enable or disable catalogue item"
       :roles +admin-write-roles+
       :body [command schema/EnabledCommand]
       :return schema/SuccessResponse
+      (extended-logging request)
       (ok (catalogue/set-catalogue-item-enabled! command)))))

src/clj/rems/api/categories.clj

@@ -51,27 +51,30 @@
         (ok (category/update-category! command))
         (not-found-json-response)))
 
-    (POST "/" []
+    (POST "/" request
       :summary "Create category. DEPRECATED, will disappear, use /create instead"
       :roles +admin-write-roles+
       :body [command schema/CreateCategoryCommand]
       :return CreateCategoryResponse
+      (extended-logging request)
       (ok (category/create-category! command)))
 
-    (PUT "/" []
+    (PUT "/" request
       :summary "Update category, DEPRECATED, will disappear, use /edit instead"
       :roles +admin-write-roles+
       :body [command schema/UpdateCategoryCommand]
       :return schema/SuccessResponse
+      (extended-logging request)
       (if (category/get-category (:category/id command))
         (ok (category/update-category! command))
         (not-found-json-response)))
 
-    (POST "/delete" []
+    (POST "/delete" request
       :summary "Delete category"
       :roles +admin-write-roles+
       :body [command schema/DeleteCategoryCommand]
       :return schema/SuccessResponse
+      (extended-logging request)
       (if (category/get-category (:category/id command))
         (ok (category/delete-category! command))
         (not-found-json-response)))))

src/clj/rems/api/email.clj

@@ -1,28 +1,31 @@
 (ns rems.api.email
   (:require [compojure.api.sweet :refer :all]
-            [rems.api.util] ; required for route :roles
+            [rems.api.util :refer [extended-logging]] ; required for route :roles
             [rems.email.core :as email]
             [ring.util.http-response :refer :all]))
 
 (def email-api
   (context "/email" []
     :tags ["email"]
 
-    (POST "/send-reminders" []
+    (POST "/send-reminders" request
       :summary "Send all reminders."
       :roles #{:api-key}
+      (extended-logging request)
       (email/generate-handler-reminder-emails!)
       (email/generate-reviewer-reminder-emails!)
       (ok "OK"))
 
-    (POST "/send-handler-reminder" []
+    (POST "/send-handler-reminder" request
       :summary "Send reminders about open applications to all handlers."
       :roles #{:api-key}
+      (extended-logging request)
       (email/generate-handler-reminder-emails!)
       (ok "OK"))
 
-    (POST "/send-reviewer-reminder" []
+    (POST "/send-reviewer-reminder" request
       :summary "Send reminders about applications pending review."
       :roles #{:api-key}
+      (extended-logging request)
       (email/generate-reviewer-reminder-emails!)
       (ok "OK"))))

src/clj/rems/api/forms.clj

@@ -78,16 +78,18 @@
       (extended-logging request)
       (ok (form/edit-form! command)))
 
-    (PUT "/archived" []
+    (PUT "/archived" request
       :summary "Archive or unarchive form"
       :roles +admin-write-roles+
       :body [command schema/ArchivedCommand]
       :return schema/SuccessResponse
+      (extended-logging request)
       (ok (form/set-form-archived! command)))
 
-    (PUT "/enabled" []
+    (PUT "/enabled" request
       :summary "Enable or disable form"
       :roles +admin-write-roles+
       :body [command schema/EnabledCommand]
       :return schema/SuccessResponse
+      (extended-logging request)
       (ok (form/set-form-enabled! command)))))

src/clj/rems/api/invitations.clj

@@ -1,7 +1,7 @@
 (ns rems.api.invitations
   (:require [compojure.api.sweet :refer :all]
             [rems.service.invitation :as invitation]
-            [rems.api.util :refer [not-found-json-response]] ; required for route :roles
+            [rems.api.util :refer [extended-logging not-found-json-response]] ; required for route :roles
             [rems.common.roles :refer [+admin-read-roles+ +admin-write-roles+]]
             [rems.schema-base :as schema-base]
             [rems.util :refer [getx-user-id]]
@@ -49,16 +49,18 @@
                                              (when (some? sent) {:sent sent})
                                              (when (some? accepted) {:accepted accepted})))))
 
-    (POST "/create" []
+    (POST "/create" request
       :summary "Create an invitation. The invitation will be sent asynchronously to the recipient."
       :roles +admin-write-roles+
       :body [command CreateInvitationCommand]
       :return CreateInvitationResponse
+      (extended-logging request)
       (ok (invitation/create-invitation! (assoc command :userid (getx-user-id)))))
 
-    (POST "/accept-invitation" []
+    (POST "/accept-invitation" request
       :summary "Accept an invitation. The invitation token will be spent."
       :roles #{:logged-in}
       :query-params [{token :- (describe s/Str "secret token of the invitation") false}]
       :return AcceptInvitationResponse
+      (extended-logging request)
       (ok (invitation/accept-invitation! {:userid (getx-user-id) :token token})))))

src/clj/rems/api/licenses.clj

@@ -3,13 +3,11 @@
             [rems.api.schema :as schema]
             [rems.service.attachment :as attachment]
             [rems.service.licenses :as licenses]
-            [rems.api.util :refer [not-found-json-response]] ; required for route :roles
+            [rems.api.util :refer [extended-logging not-found-json-response]] ; required for route :roles
             [rems.common.roles :refer [+admin-read-roles+ +admin-write-roles+]]
             [rems.schema-base :as schema-base]
             [rems.util :refer [getx-user-id]]
-            [ring.middleware.multipart-params :as multipart]
             [ring.swagger.json-schema :as rjs]
-            [ring.swagger.upload :as upload]
             [ring.util.http-response :refer :all]
             [schema.core :as s]))
 
@@ -61,39 +59,44 @@
         (ok license)
         (not-found-json-response)))
 
-    (POST "/create" []
+    (POST "/create" request
       :summary "Create license"
       :roles +admin-write-roles+
       :body [command CreateLicenseCommand]
       :return CreateLicenseResponse
+      (extended-logging request)
       (ok (licenses/create-license! command)))
 
-    (PUT "/archived" []
+    (PUT "/archived" request
       :summary "Archive or unarchive license"
       :roles +admin-write-roles+
       :body [command schema/ArchivedCommand]
       :return schema/SuccessResponse
+      (extended-logging request)
       (ok (licenses/set-license-archived! command)))
 
-    (PUT "/enabled" []
+    (PUT "/enabled" request
       :summary "Enable or disable license"
       :roles +admin-write-roles+
       :body [command schema/EnabledCommand]
       :return schema/SuccessResponse
+      (extended-logging request)
       (ok (licenses/set-license-enabled! command)))
 
-    (POST "/add_attachment" []
+    (POST "/add_attachment" request
       :summary "Add an attachment file that will be used in a license"
       :roles +admin-write-roles+
       :multipart-params [file :- schema/FileUpload]
       :return AttachmentMetadata
+      (extended-logging request)
       (ok (licenses/create-license-attachment! file (getx-user-id))))
 
-    (POST "/remove_attachment" []
+    (POST "/remove_attachment" request
       :summary "Remove an attachment that could have been used in a license."
       :roles +admin-write-roles+
       :query-params [attachment-id :- (describe s/Int "attachment id")]
       :return schema/SuccessResponse
+      (extended-logging request)
       (ok {:success (some? (licenses/remove-license-attachment! attachment-id))}))
 
     (GET "/attachments/:attachment-id" []