Skip to content

Commit f81a953

Browse files
prb112prb112
authored
Merge pull request #2973 from IBM/issue-harden-audit-log
Harden Bulk Data Audit Logging with Skippable Updates
2 parents bcf502b + 03c65c0 commit f81a953

2 files changed

Lines changed: 75 additions & 39 deletions

File tree

‎fhir-bulkdata-webapp/src/main/java/com/ibm/fhir/bulkdata/audit/BulkAuditLogger.java‎

Lines changed: 33 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -250,9 +250,39 @@ public void logUpdateOnImport(Resource oldResource, Resource updatedResource, Da
250250
final String METHODNAME = "logUpdateOnImport";
251251
log.entering(CLASSNAME, METHODNAME);
252252
if (shouldLog()) {
253-
// Right now, we don't log or treat the oldResource. The signature is left for the commonality with the REST
254-
// Audit Logger.
255-
log(AuditLogEventType.FHIR_UPDATE, "U", "FHIR BulkData Update request", null, updatedResource, startTime, endTime, responseStatus, null, null, location, users);
253+
if (Response.Status.CREATED.equals(responseStatus)) {
254+
logCreateOnImport(updatedResource, startTime, endTime, responseStatus, location, users);
255+
} else {
256+
// Right now, we don't log or treat the oldResource. The signature is left for the commonality with the REST
257+
// Audit Logger.
258+
log(AuditLogEventType.FHIR_UPDATE, "U", "FHIR BulkData Update request", null, updatedResource, startTime, endTime, responseStatus, null, null, location, users);
259+
}
260+
}
261+
log.exiting(CLASSNAME, METHODNAME);
262+
}
263+
264+
/**
265+
* Builds an audit log entry for an 'update' skipped in a bulkdata service invocation.
266+
*
267+
* @param resource
268+
* The updated version of the Resource.
269+
* @param startTime
270+
* The start time of the update request execution.
271+
* @param endTime
272+
* The end time of the update request execution.
273+
* @param responseStatus
274+
* The response status.
275+
* @param location
276+
* the destination or source for the export or import
277+
* @param users
278+
* the principals that initiated the request
279+
*/
280+
public void logUpdateOnImportSkipped(Resource resource, Date startTime, Date endTime, Response.Status responseStatus, String location,
281+
String users) throws Exception {
282+
final String METHODNAME = "logUpdateOnImport";
283+
log.entering(CLASSNAME, METHODNAME);
284+
if (shouldLog()) {
285+
log(AuditLogEventType.FHIR_UPDATE, "U", "FHIR BulkData Update Resource Skipped request", null, resource, startTime, endTime, responseStatus, null, null, location, users);
256286
}
257287
log.exiting(CLASSNAME, METHODNAME);
258288
}

‎fhir-bulkdata-webapp/src/main/java/com/ibm/fhir/bulkdata/jbatch/load/ChunkWriter.java‎

Lines changed: 42 additions & 36 deletions
Original file line numberDiff line numberDiff line change
@@ -54,11 +54,11 @@
5454
import com.ibm.fhir.operation.bulkdata.model.type.OperationFields;
5555
import com.ibm.fhir.operation.bulkdata.model.type.StorageType;
5656
import com.ibm.fhir.persistence.FHIRPersistence;
57+
import com.ibm.fhir.persistence.InteractionStatus;
5758
import com.ibm.fhir.persistence.SingleResourceResult;
5859
import com.ibm.fhir.persistence.context.FHIRPersistenceContext;
5960
import com.ibm.fhir.persistence.context.FHIRPersistenceContextFactory;
6061
import com.ibm.fhir.persistence.context.FHIRPersistenceEvent;
61-
import com.ibm.fhir.persistence.exception.FHIRPersistenceException;
6262
import com.ibm.fhir.persistence.helper.FHIRPersistenceHelper;
6363
import com.ibm.fhir.persistence.helper.FHIRTransactionHelper;
6464
import com.ibm.fhir.persistence.payload.PayloadPersistenceHelper;
@@ -186,7 +186,6 @@ public void writeItems(List<java.lang.Object> arg0) throws Exception {
186186

187187
// Get the Skippable Update status
188188
boolean skip = adapter.enableSkippableUpdates();
189-
Map<String,SaltHash> localCache = new HashMap<>();
190189
try {
191190
for (Object objResJsonList : arg0) {
192191
@SuppressWarnings("unchecked")
@@ -222,13 +221,7 @@ public void writeItems(List<java.lang.Object> arg0) throws Exception {
222221

223222
// Set up the persistence context to include the deleted resources when we read
224223
FHIRPersistenceContext persistenceContext = FHIRPersistenceContextFactory.createPersistenceContext(event, true);
225-
long startTime = System.currentTimeMillis();
226-
operationOutcome = conditionalFingerprintUpdate(chunkData, skip, localCache, fhirPersistence, persistenceContext, id, fhirResource);
227-
if (auditLogger.shouldLog()) {
228-
long endTime = System.currentTimeMillis();
229-
String location = "@source:" + ctx.getSource() + "/" + ctx.getImportPartitionWorkitem();
230-
auditLogger.logUpdateOnImport(null, fhirResource, new Date(startTime), new Date(endTime), Response.Status.OK, location, "BulkDataOperator");
231-
}
224+
operationOutcome = conditionalFingerprintUpdate(chunkData, skip, fhirPersistence, persistenceContext, id, fhirResource, ctx);
232225
}
233226

234227
succeededNum++;
@@ -293,15 +286,17 @@ public void writeItems(List<java.lang.Object> arg0) throws Exception {
293286
*
294287
* @param chunkData the transient user data used increment the number of skips
295288
* @param skip should skip the resource if it matches
296-
* @param localCache map containing the key-saltHash
297289
* @param persistence used to facilitate the calls to the underlying db
298290
* @param context used in db calls
299291
* @param logicalId the logical id of the FHIR resource (e.g. 1-2-3-4)
300292
* @param resource the FHIR Resource
293+
* @param ctx the bulk data context
301294
* @return outcomes including information or warnings
302-
* @throws FHIRPersistenceException
295+
* @throws Exception
303296
*/
304-
public OperationOutcome conditionalFingerprintUpdate(ImportTransientUserData chunkData, boolean skip, Map<String, SaltHash> localCache, FHIRPersistence persistence, FHIRPersistenceContext context, String logicalId, Resource resource) throws FHIRPersistenceException {
297+
public OperationOutcome conditionalFingerprintUpdate(ImportTransientUserData chunkData, boolean skip, FHIRPersistence persistence, FHIRPersistenceContext context, String logicalId, Resource resource, BulkDataContext ctx) throws Exception {
298+
long startTime = System.currentTimeMillis();
299+
Response.Status status = Response.Status.OK;
305300

306301
// Since issue 1869, we must perform the read at this point in order to obtain the
307302
// latest version id. The persistence layer no longer makes any changes to the
@@ -317,27 +312,29 @@ public OperationOutcome conditionalFingerprintUpdate(ImportTransientUserData chu
317312

318313
// If the resource was previously deleted, we need to treat this as a not to skip, otherwise we end up with really inconsistent data
319314
// when there is a DELETED resource.
315+
boolean skipped = false;
320316
OperationOutcome oo;
321-
if (skip && !oldResourceResult.isDeleted()) {
322-
// Key is scoped to the ResourceType.
323-
String key = resourceType + "/" + logicalId;
324-
SaltHash oldBaseLine = localCache.get(key);
325-
326-
ResourceFingerprintVisitor fp = new ResourceFingerprintVisitor();
327-
if (oldBaseLine == null) {
328-
// If the resource exists, then we need to fingerprint.
329-
if (oldResource != null) {
330-
ResourceFingerprintVisitor fpOld = new ResourceFingerprintVisitor();
331-
oldResource.accept(fpOld);
332-
oldBaseLine = fpOld.getSaltAndHash();
333-
fp = new ResourceFingerprintVisitor(oldBaseLine);
334-
}
317+
if (!skip || oldResourceResult.isDeleted() || oldResource == null) {
318+
SingleResourceResult<? extends Resource> result = persistence.updateWithMeta(context, resource);
319+
320+
if (result.getStatus() == InteractionStatus.MODIFIED) {
321+
status = Response.Status.CREATED;
335322
}
323+
oo = result.getOutcome();
324+
} else {
325+
// Fingerprint old base line
326+
ResourceFingerprintVisitor fpOld = new ResourceFingerprintVisitor();
327+
oldResource.accept(fpOld);
328+
SaltHash oldBaseLine = fpOld.getSaltAndHash();
336329

330+
// Fingerprint new base line
331+
ResourceFingerprintVisitor fp = new ResourceFingerprintVisitor(oldBaseLine);
337332
resource.accept(fp);
338333
SaltHash newBaseLine = fp.getSaltAndHash();
339334

340335
if (oldBaseLine != null && oldBaseLine.equals(newBaseLine)) {
336+
// Outcome is an informational message (no change to datastore)
337+
String key = resource.getClass().getSimpleName() + "/" + logicalId;
341338
if (logger.isLoggable(Level.FINE)) {
342339
logger.fine("Skipping $import - update for '" + key + "'");
343340
}
@@ -347,22 +344,31 @@ public OperationOutcome conditionalFingerprintUpdate(ImportTransientUserData chu
347344
.severity(IssueSeverity.INFORMATION)
348345
.code(IssueType.INFORMATIONAL)
349346
.details(CodeableConcept.builder()
350-
.text(string("Update resource matches the existing resource; skipping the update for '" + key + "'"))
347+
.text(string("Update to an existing resource matches the stored resource's hash; skipping the update for '" + key + "'"))
351348
.build())
352349
.build())
353350
.build();
351+
skipped = true;
354352
} else {
353+
// Outcome is an Update
355354
// We need to update the db and update the local cache
356-
if (oldResource != null) {
357-
// Old Resource is set so we avoid an extra read
358-
context.getPersistenceEvent().setPrevFhirResource(oldResource);
359-
}
360-
oo = persistence.updateWithMeta(context, resource).getOutcome();
361-
localCache.put(key, newBaseLine);
355+
// Old Resource is set so we avoid an extra read
356+
context.getPersistenceEvent().setPrevFhirResource(oldResource);
357+
SingleResourceResult<? extends Resource> result = persistence.updateWithMeta(context, resource);
358+
oo = result.getOutcome();
359+
}
360+
}
361+
362+
// Audit Logging
363+
if (auditLogger.shouldLog()) {
364+
long endTime = System.currentTimeMillis();
365+
String location = "@source:" + ctx.getSource() + "/" + ctx.getImportPartitionWorkitem();
366+
if (!skipped) {
367+
auditLogger.logUpdateOnImport(oldResource, resource, new Date(startTime), new Date(endTime), status, location, "BulkDataOperator");
368+
} else {
369+
auditLogger.logUpdateOnImportSkipped(resource, new Date(startTime), new Date(endTime), status, location, "BulkDataOperator");
362370
}
363-
} else {
364-
oo = persistence.updateWithMeta(context, resource).getOutcome();
365371
}
366372
return oo;
367373
}
368-
}
374+
}

0 commit comments

Comments
 (0)