[REVIEW] Reviewing implementation

cds-plugin.js

@@ -5,67 +5,62 @@ const { augmentContext, calcMods4Before, calcMods4After, emitMods } = require('.
 const { hasPersonalData } = require('./lib/utils')
 
 // TODO: why does cds.requires.audit-log: false in sample package.json not work ootb?!
+// REVIST: It does, doesn't it?
 
-/*
- * anything to do?
- */
-cds.on('loaded', (/* model */) => {
-  // TODO
-})
 
 /*
  * Add generic audit logging handlers
  */
-cds.on('serving', service => {
-  if (!(service instanceof cds.ApplicationService)) return
-
-  if (cds.db)
-    enhance(service)
-  else // > deferred
-    cds.on('connect', srv => srv.isDatabaseService && enhance(service))
-})
-
-const enhance = service => {
-  const relevantEntities = []
-  for (const entity of service.entities) if (hasPersonalData(entity)) relevantEntities.push(entity)
-  if (!relevantEntities.length) return
+cds.on('served', services => {
+  const db = cds.db // REVISIT: Why does this has to happen on db layer?
+  for (let srv of services) {
 
-  /*
-   * REVISIT: diff() doesn't work in srv after phase but foreign key propagation has not yet taken place in srv before phase
-   *          -> calc diff in db layer and store in audit data structure at context
-   *          -> REVISIT for GA: clear req._.partialPersistentState?
-   */
-  augmentContext._initial = true
+    if (!(srv instanceof cds.ApplicationService)) continue
 
-  for (const entity of relevantEntities) {
     /*
-     * CREATE
+     * REVISIT: diff() doesn't work in srv after phase but foreign key propagation has not yet taken place in srv before phase
+     *          -> calc diff in db layer and store in audit data structure at context
+     *          -> REVISIT for GA: clear req._.partialPersistentState?
      */
-    cds.db.before('CREATE', entity, augmentContext)
-    // create -> all new -> calcModificationLogsHandler in after phase
-    cds.db.after('CREATE', entity, calcMods4After)
-    service.after('CREATE', entity, emitMods)
 
-    /*
-     * READ
-     */
-    service.after('READ', entity, auditAccess)
+    for (const entity of srv.entities) {
 
-    /*
-     * UPDATE
-     */
-    cds.db.before('UPDATE', entity, augmentContext)
-    // update -> mixed (via deep) -> calcModificationLogsHandler in before and after phase
-    cds.db.before('UPDATE', entity, calcMods4Before)
-    cds.db.after('UPDATE', entity, calcMods4After)
-    service.after('UPDATE', entity, emitMods)
+      // REVISIT: Disallows customers adding personal data extension fields
+      if (!hasPersonalData(entity)) continue
 
-    /*
-     * DELETE
-     */
-    cds.db.before('DELETE', entity, augmentContext)
-    // delete -> all done -> calcModificationLogsHandler in before phase
-    cds.db.before('DELETE', entity, calcMods4Before)
-    service.after('DELETE', entity, emitMods)
+      /*
+       * CREATE
+       */
+      // REVISIT: 3 handlers for CREATE ?!? -> could go into one .on handler
+      db.before('CREATE', entity, augmentContext)
+      // create -> all new -> calcModificationLogsHandler in after phase
+      db.after('CREATE', entity, calcMods4After)
+      srv.after('CREATE', entity, emitMods)
+
+      /*
+       * READ
+       */
+      // REVISIT: Only if we have sensitive data?
+      srv.after('READ', entity, auditAccess)
+
+      /*
+       * UPDATE
+       */
+      // REVISIT: 4 handlers for UPDATE ?!? -> could go into one .on handler
+      db.before('UPDATE', entity, augmentContext)
+      // update -> mixed (via deep) -> calcModificationLogsHandler in before and after phase
+      db.before('UPDATE', entity, calcMods4Before)
+      db.after('UPDATE', entity, calcMods4After) // REVISIT: Why do we have to calculate modifications twice?
+      srv.after('UPDATE', entity, emitMods)
+
+      /*
+      * DELETE
+      */
+     // REVISIT: 3 handlers for DELETE ?!? -> could go into one .on handler
+      db.before('DELETE', entity, augmentContext)
+      // delete -> all done -> calcModificationLogsHandler in before phase
+      db.before('DELETE', entity, calcMods4Before)
+      srv.after('DELETE', entity, emitMods)
+    }
   }
-}
+})

index.cds

@@ -1,6 +1,6 @@
 namespace sap.auditlog;
 
-@protocol: 'none'
+// @protocol: 'none' //> only required if we add .model in cds.requires.audit-log
 service AuditLogService {
 
   action log(event : String, data : LogEntry);

lib/modification.js

@@ -19,9 +19,10 @@ let audit
 
 const augmentContext = async function (req) {
   // store diff in audit data structure at context
-  const _audit = req.context._audit || (req.context._audit = {})
+  const _audit = req.context._audit ??= {}
   if (!_audit.diffs) _audit.diffs = new Map()
   _audit.diffs.set(req._.query, await req.diff())
+  // REVISIT: When do we have serveral diffs?
 }
 
 const _getOldAndNew = (action, row, key) => {
@@ -35,7 +36,9 @@ const _getOldAndNew = (action, row, key) => {
 const _addAttribute = (log, action, row, key) => {
   if (!log.attributes.find(ele => ele.name === key)) {
     const { oldValue, newValue } = _getOldAndNew(action, row, key)
-    if (oldValue !== newValue) log.attributes.push({ name: key, old: String(oldValue), new: String(newValue) })
+    // REVISIT: Why should we log all values as strings?
+    // if (oldValue !== newValue) log.attributes.push({ name: key, old: String(oldValue), new: String(newValue) })
+    if (oldValue !== newValue) log.attributes.push({ name: key, old: oldValue, new: newValue })
   }
 }
 
@@ -124,6 +127,8 @@ const emitMods = async function (_, req) {
   await Promise.all(modifications.map(modification => audit.log('PersonalDataModified', modification)))
 }
 
+augmentContext._initial = true
+
 module.exports = {
   augmentContext,
   calcMods4Before,

lib/utils.js

@@ -64,14 +64,18 @@ const createLogEntry = (logs, entity, row) => {
 }
 
 const addObjectID = (log, row, key) => {
-  if (!(key in log.dataObject.id) && key !== 'IsActiveEntity') log.dataObject.id[key] = String(row[key])
+  // REVISIT: Why should we log all values as strings?
+  // if (!(key in log.dataObject.id) && key !== 'IsActiveEntity') log.dataObject.id[key] = String(row[key])
+  if (!(key in log.dataObject.id) && key !== 'IsActiveEntity') log.dataObject.id[key] = row[key]
 }
 
 const addDataSubject = (log, row, key, entity) => {
   if (!log.dataSubject.type) log.dataSubject.type = entity.name
   if (!(key in log.dataSubject.id)) {
     const value = row[key] || (row._old && row._old[key])
-    log.dataSubject.id[key] = String(value)
+    // REVISIT: Why should we log all values as strings?
+    // log.dataSubject.id[key] = String(value)
+    log.dataSubject.id[key] = value
   }
 }
 
@@ -129,7 +133,9 @@ const _getDataSubjectIdPromise = ({ dataSubjectEntity, subs }, row, req, model)
 
   return cqn.then(res => {
     const id = {}
-    for (const k in res[0]) id[k] = String(res[0][k])
+    // REVISIT: Why should we log all values as strings?
+    // for (const k in res[0]) id[k] = String(res[0][k])
+    for (const k in res[0]) id[k] = res[0][k]
     return id
   })
 }

package.json

@@ -32,9 +32,9 @@
       "audit-log": true,
       "kinds": {
         "audit-log": {
-          "_model": "@cap-js/audit-logging",
-          "_service": "sap.auditlog.AuditLogService",
-          "_handle": [ "READ", "WRITE" ],
+          "-model": "@cap-js/audit-logging",
+          "-service": "sap.auditlog.AuditLogService",
+          "-handle": [ "READ", "WRITE" ],
           "[development]": {
             "kind": "audit-log-to-console"
           },
@@ -44,11 +44,13 @@
         },
         "audit-log-to-console": {
           "impl": "@cap-js/audit-logging/srv/log2console",
+          "-kind": "rest",
           "outbox": false
         },
         "audit-log-to-library": {
           "impl": "@cap-js/audit-logging/srv/log2library",
           "vcap": { "label": "auditlog" },
+          "-kind": "rest",
           "outbox": true
         }
       }

srv/log2console.js

@@ -1,17 +1,13 @@
 const AuditLogService = require('./service')
-
-// the default depth of 2 is not enough to see the full logs
-require('util').inspect.defaultOptions.depth = 3
+const { inspect } = require('util')
+const colors = process.stdout.isTTY
 
 module.exports = class AuditLog2Console extends AuditLogService {
   async init() {
-    // call AuditLogService's init
-    await super.init()
-
     this.on('*', function (req) {
       const { event, data } = req
-
-      console.log(`[audit-log] - ${event}:`, data)
+      console.log('[audit-log] -', event, inspect(data,{colors,depth:3}))
     })
+    await super.init()
   }
 }

srv/log2library.js

@@ -137,7 +137,8 @@ module.exports = class AuditLog2Library extends AuditLogService {
  */
 
 function _getAttributeToLog(ele) {
-  return { name: ele.name, old: ele.old || 'null', new: ele.new || 'null' }
+  // REVISIT: Why should we log null as string?
+  return ele
 }
 
 /*

srv/service.js

@@ -1,72 +1,54 @@
 const cds = require('@sap/cds')
-
-// REVISIT: cds.OutboxService or technique to avoid extending OutboxService
 const OutboxService = require('@sap/cds/libx/_runtime/messaging/Outbox')
-
-const ANONYMOUS = 'anonymous'
-
-const _augment = data => {
-  data.id = data.id || cds.utils.uuid()
-  data.tenant = data.tenant || cds.context.tenant || ANONYMOUS
-  data.user = data.user || cds.context.user?.id || ANONYMOUS
-  data.timestamp = data.timestamp || cds.context.timestamp
-  return data
-}
+// REVISIT: cds.OutboxService or technique to avoid extending OutboxService
+// REVISIT: OutboxService should not be base class but a decorator
 
 module.exports = class AuditLogService extends OutboxService {
-  async emit(first, second) {
-    let { event, data } = typeof first === 'object' ? first : { event: first, data: second }
-    if (data.event && data.data) ({ event, data } = data)
-    data = _augment(data)
 
+  async emit(event, data) {
+
+    // REVISIT: That should not be neccessary, as the * handlers react on both .emit or .send / handled by the outbox, if at all.
     // immediate or deferred?
     if (!this.options.outbox) return this.send(event, data)
+
+    if (typeof event === 'object') ({ event, data } = event) // We shouldn't neccessarily need that
+    if (data.event && data.data) ({ event, data } = data) // REVISIT: Why is that?
+    data = _augment(data)
+
     try {
       // this will open a new (detached!) tx -> preserve user
+      // REVISIT: Why do we need a new root tx?
+      // REVISIT: Why do we construct a new cds.Request? -> done in base class
       await this.tx(() => super.send(new cds.Request({ event, data })))
     } catch (e) {
+      // REVISIT: Who throws ERR_ASSERTION
       if (e.code === 'ERR_ASSERTION') e.unrecoverable = true
       throw e
     }
   }
 
   async send(event, data) {
-    if (data.event && data.data) ({ event, data } = data)
-
+    if (typeof event === 'object') ({ event, data } = event) // We shouldn't neccessarily need that
+    if (data.event && data.data) ({ event, data } = data) // REVISIT: Why is that?
     return super.send(event, _augment(data))
   }
 
-  /*
-   * new api (await audit.log/logSync(event, data))
-   */
-
-  log(event, data = {}) {
+  log(event, data) {
     return this.emit(event, data)
   }
 
-  logSync(event, data = {}) {
+  logSync(event, data) {
     return this.send(event, data)
   }
 
-  /*
-   * compat api (await audit.<event>(data))
-   */
-
-  dataAccessLog(data = {}) {
-    return this.emit('SensitiveDataRead', data)
-  }
-
-  dataModificationLog(data = {}) {
-    return this.emit('PersonalDataModified', data)
-  }
+}
 
-  configChangeLog(data = {}) {
-    // REVISIT: event name
-    return this.emit('ConfigurationModified', data)
-  }
 
-  securityLog(data = {}) {
-    // REVISIT: event name
-    return this.emit('SecurityEvent', data)
-  }
+const _augment = data => {
+  let ctx = cds.context
+  if (!data.id) data.id = cds.utils.uuid()
+  if (!data.tenant) data.tenant = ctx.tenant //|| ANONYMOUS
+  if (!data.user) data.user = ctx.user?.id //|| ANONYMOUS
+  if (!data.timestamp) data.timestamp = ctx.timestamp
+  return data
 }