001/* 002 * (C) Copyright 2006-2017 Nuxeo (http://nuxeo.com/) and others. 003 * 004 * Licensed under the Apache License, Version 2.0 (the "License"); 005 * you may not use this file except in compliance with the License. 006 * You may obtain a copy of the License at 007 * 008 * http://www.apache.org/licenses/LICENSE-2.0 009 * 010 * Unless required by applicable law or agreed to in writing, software 011 * distributed under the License is distributed on an "AS IS" BASIS, 012 * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. 013 * See the License for the specific language governing permissions and 014 * limitations under the License. 015 * 016 * Contributors: 017 * Thierry Delprat 018 */ 019package org.nuxeo.ecm.platform.audit.service; 020 021import static org.nuxeo.ecm.core.schema.FacetNames.SYSTEM_DOCUMENT; 022import static org.nuxeo.ecm.platform.audit.api.BuiltinLogEntryData.LOG_CATEGORY; 023import static org.nuxeo.ecm.platform.audit.api.BuiltinLogEntryData.LOG_DOC_PATH; 024import static org.nuxeo.ecm.platform.audit.api.BuiltinLogEntryData.LOG_DOC_UUID; 025import static org.nuxeo.ecm.platform.audit.api.BuiltinLogEntryData.LOG_EVENT_DATE; 026import static org.nuxeo.ecm.platform.audit.api.BuiltinLogEntryData.LOG_EVENT_ID; 027import static org.nuxeo.ecm.platform.audit.api.BuiltinLogEntryData.LOG_ID; 028import static org.nuxeo.ecm.platform.audit.api.BuiltinLogEntryData.LOG_REPOSITORY_ID; 029import static org.nuxeo.ecm.platform.audit.impl.StreamAuditWriter.COMPUTATION_NAME; 030import static org.nuxeo.ecm.platform.audit.listener.StreamAuditEventListener.STREAM_AUDIT_ENABLED_PROP; 031import static org.nuxeo.ecm.platform.audit.listener.StreamAuditEventListener.STREAM_NAME; 032 033import java.io.Serializable; 034import java.security.Principal; 035import java.util.ArrayList; 036import java.util.Calendar; 037import java.util.Collection; 038import java.util.Date; 039import java.util.List; 040import java.util.Map; 041import java.util.Map.Entry; 042import java.util.Set; 043import java.util.concurrent.TimeUnit; 044 045import javax.el.ELException; 046 047import org.apache.commons.lang3.ArrayUtils; 048import org.apache.logging.log4j.Logger; 049import org.jboss.el.ExpressionFactoryImpl; 050import org.nuxeo.ecm.core.api.CoreInstance; 051import org.nuxeo.ecm.core.api.CoreSession; 052import org.nuxeo.ecm.core.api.DocumentModel; 053import org.nuxeo.ecm.core.api.DocumentModelList; 054import org.nuxeo.ecm.core.api.DocumentNotFoundException; 055import org.nuxeo.ecm.core.api.DocumentRef; 056import org.nuxeo.ecm.core.api.LifeCycleConstants; 057import org.nuxeo.ecm.core.api.NuxeoException; 058import org.nuxeo.ecm.core.api.NuxeoPrincipal; 059import org.nuxeo.ecm.core.api.PathRef; 060import org.nuxeo.ecm.core.api.PropertyException; 061import org.nuxeo.ecm.core.api.ScrollResult; 062import org.nuxeo.ecm.core.api.event.DocumentEventTypes; 063import org.nuxeo.ecm.core.api.security.SecurityConstants; 064import org.nuxeo.ecm.core.event.DeletedDocumentModel; 065import org.nuxeo.ecm.core.event.Event; 066import org.nuxeo.ecm.core.event.EventBundle; 067import org.nuxeo.ecm.core.event.EventContext; 068import org.nuxeo.ecm.core.event.impl.DocumentEventContext; 069import org.nuxeo.ecm.core.query.sql.model.Operator; 070import org.nuxeo.ecm.core.query.sql.model.OrderByExprs; 071import org.nuxeo.ecm.core.query.sql.model.Predicate; 072import org.nuxeo.ecm.core.query.sql.model.Predicates; 073import org.nuxeo.ecm.core.query.sql.model.QueryBuilder; 074import org.nuxeo.ecm.platform.audit.api.AuditQueryBuilder; 075import org.nuxeo.ecm.platform.audit.api.AuditStorage; 076import org.nuxeo.ecm.platform.audit.api.ExtendedInfo; 077import org.nuxeo.ecm.platform.audit.api.FilterMapEntry; 078import org.nuxeo.ecm.platform.audit.api.LogEntry; 079import org.nuxeo.ecm.platform.audit.impl.LogEntryImpl; 080import org.nuxeo.ecm.platform.audit.service.extension.AdapterDescriptor; 081import org.nuxeo.ecm.platform.audit.service.extension.AuditBackendDescriptor; 082import org.nuxeo.ecm.platform.audit.service.extension.ExtendedInfoDescriptor; 083import org.nuxeo.ecm.platform.el.ExpressionContext; 084import org.nuxeo.ecm.platform.el.ExpressionEvaluator; 085import org.nuxeo.lib.stream.log.LogManager; 086import org.nuxeo.lib.stream.log.Name; 087import org.nuxeo.runtime.api.Framework; 088import org.nuxeo.runtime.stream.StreamService; 089 090/** 091 * Abstract class to share code between {@link AuditBackend} implementations 092 * 093 * @author tiry 094 */ 095public abstract class AbstractAuditBackend implements AuditBackend, AuditStorage { 096 097 protected static final Logger log = org.apache.logging.log4j.LogManager.getLogger(AbstractAuditBackend.class); 098 099 public static final String FORCE_AUDIT_FACET = "ForceAudit"; 100 101 protected final NXAuditEventsService component; 102 103 protected final AuditBackendDescriptor config; 104 105 protected AbstractAuditBackend(NXAuditEventsService component, AuditBackendDescriptor config) { 106 this.component = component; 107 this.config = config; 108 } 109 110 protected AbstractAuditBackend() { 111 this(null, null); 112 } 113 114 protected final ExpressionEvaluator expressionEvaluator = new ExpressionEvaluator(new ExpressionFactoryImpl()); 115 116 protected DocumentModel guardedDocument(CoreSession session, DocumentRef reference) { 117 if (session == null) { 118 return null; 119 } 120 if (reference == null) { 121 return null; 122 } 123 try { 124 return session.getDocument(reference); 125 } catch (DocumentNotFoundException e) { 126 return null; 127 } 128 } 129 130 protected DocumentModelList guardedDocumentChildren(CoreSession session, DocumentRef reference) { 131 return session.getChildren(reference); 132 } 133 134 protected LogEntry doCreateAndFillEntryFromDocument(DocumentModel doc, Principal principal) { 135 LogEntry entry = newLogEntry(); 136 entry.setDocPath(doc.getPathAsString()); 137 entry.setDocType(doc.getType()); 138 entry.setDocUUID(doc.getId()); 139 entry.setRepositoryId(doc.getRepositoryName()); 140 entry.setPrincipalName(SecurityConstants.SYSTEM_USERNAME); 141 entry.setCategory("eventDocumentCategory"); 142 entry.setEventId(DocumentEventTypes.DOCUMENT_CREATED); 143 // why hard-code it if we have the document life cycle? 144 entry.setDocLifeCycle("project"); 145 Calendar creationDate = (Calendar) doc.getProperty("dublincore", "created"); 146 if (creationDate != null) { 147 entry.setEventDate(creationDate.getTime()); 148 } 149 150 doPutExtendedInfos(entry, null, doc, principal); 151 152 return entry; 153 } 154 155 protected void doPutExtendedInfos(LogEntry entry, EventContext eventContext, DocumentModel source, 156 Principal principal) { 157 158 ExpressionContext context = new ExpressionContext(); 159 if (eventContext != null) { 160 expressionEvaluator.bindValue(context, "message", eventContext); 161 } 162 if (source != null) { 163 expressionEvaluator.bindValue(context, "source", source); 164 // inject now the adapters 165 for (AdapterDescriptor ad : component.getDocumentAdapters()) { 166 if (source instanceof DeletedDocumentModel) { 167 continue; // skip 168 } 169 Object adapter = source.getAdapter(ad.getKlass()); 170 if (adapter != null) { 171 expressionEvaluator.bindValue(context, ad.getName(), adapter); 172 } 173 } 174 } 175 if (principal != null) { 176 expressionEvaluator.bindValue(context, "principal", principal); 177 } 178 179 // Global extended info 180 populateExtendedInfo(entry, source, context, component.getExtendedInfoDescriptors()); 181 // Event id related extended info 182 populateExtendedInfo(entry, source, context, 183 component.getEventExtendedInfoDescriptors().get(entry.getEventId())); 184 185 if (eventContext != null) { 186 @SuppressWarnings("unchecked") 187 Map<String, Serializable> map = (Map<String, Serializable>) eventContext.getProperty("extendedInfos"); 188 if (map != null) { 189 Map<String, ExtendedInfo> extendedInfos = entry.getExtendedInfos(); 190 for (Entry<String, Serializable> en : map.entrySet()) { 191 Serializable value = en.getValue(); 192 if (value != null) { 193 extendedInfos.put(en.getKey(), newExtendedInfo(value)); 194 } 195 } 196 } 197 } 198 } 199 200 /** 201 * @since 7.4 202 */ 203 protected void populateExtendedInfo(LogEntry entry, DocumentModel source, ExpressionContext context, 204 Collection<ExtendedInfoDescriptor> extInfos) { 205 if (extInfos != null) { 206 Map<String, ExtendedInfo> extendedInfos = entry.getExtendedInfos(); 207 for (ExtendedInfoDescriptor descriptor : extInfos) { 208 String exp = descriptor.getExpression(); 209 Serializable value; 210 try { 211 value = expressionEvaluator.evaluateExpression(context, exp, Serializable.class); 212 } catch (PropertyException | UnsupportedOperationException e) { 213 if (source instanceof DeletedDocumentModel) { 214 log.debug("Can not evaluate the expression: {} on a DeletedDocumentModel, skipping.", exp); 215 } 216 continue; 217 } catch (DocumentNotFoundException e) { 218 if (!DocumentEventTypes.DOCUMENT_REMOVED.equals(entry.getEventId())) { 219 log.error("Not found: {}, entry: {}", e.getMessage(), entry, e); 220 } 221 continue; 222 } catch (ELException e) { 223 continue; 224 } 225 if (value == null) { 226 continue; 227 } 228 extendedInfos.put(descriptor.getKey(), newExtendedInfo(value)); 229 } 230 } 231 } 232 233 @Override 234 public Set<String> getAuditableEventNames() { 235 return component.getAuditableEventNames(); 236 } 237 238 @Override 239 public LogEntry buildEntryFromEvent(Event event) { 240 EventContext ctx = event.getContext(); 241 String eventName = event.getName(); 242 Date eventDate = new Date(event.getTime()); 243 244 LogEntry entry = newLogEntry(); 245 entry.setEventId(eventName); 246 entry.setEventDate(eventDate); 247 248 if (ctx instanceof DocumentEventContext) { 249 DocumentEventContext docCtx = (DocumentEventContext) ctx; 250 DocumentModel document = docCtx.getSourceDocument(); 251 if (document.hasFacet(SYSTEM_DOCUMENT) && !document.hasFacet(FORCE_AUDIT_FACET)) { 252 // do not log event on System documents 253 // unless it has the FORCE_AUDIT_FACET facet 254 return null; 255 } 256 257 Boolean disabled = (Boolean) docCtx.getProperty(NXAuditEventsService.DISABLE_AUDIT_LOGGER); 258 if (disabled != null && disabled.booleanValue()) { 259 // don't log events with this flag 260 return null; 261 } 262 NuxeoPrincipal principal = docCtx.getPrincipal(); 263 Map<String, Serializable> properties = docCtx.getProperties(); 264 265 entry.setDocUUID(document.getId()); 266 entry.setDocPath(document.getPathAsString()); 267 entry.setDocType(document.getType()); 268 entry.setRepositoryId(document.getRepositoryName()); 269 if (principal != null) { 270 entry.setPrincipalName(principal.getActingUser()); 271 } else { 272 log.warn("received event {} with null principal", eventName); 273 } 274 entry.setComment((String) properties.get("comment")); 275 if (document instanceof DeletedDocumentModel) { 276 entry.setComment("Document does not exist anymore!"); 277 } else { 278 if (document.isLifeCycleLoaded()) { 279 entry.setDocLifeCycle(document.getCurrentLifeCycleState()); 280 } 281 } 282 if (LifeCycleConstants.TRANSITION_EVENT.equals(eventName)) { 283 entry.setDocLifeCycle((String) docCtx.getProperty(LifeCycleConstants.TRANSTION_EVENT_OPTION_TO)); 284 } 285 String category = (String) properties.get("category"); 286 if (category != null) { 287 entry.setCategory(category); 288 } else { 289 entry.setCategory("eventDocumentCategory"); 290 } 291 292 doPutExtendedInfos(entry, docCtx, document, principal); 293 294 } else { 295 NuxeoPrincipal principal = ctx.getPrincipal(); 296 Map<String, Serializable> properties = ctx.getProperties(); 297 298 if (principal != null) { 299 entry.setPrincipalName(principal.getActingUser()); 300 } 301 entry.setComment((String) properties.get("comment")); 302 303 String category = (String) properties.get("category"); 304 entry.setCategory(category); 305 306 doPutExtendedInfos(entry, ctx, null, principal); 307 308 } 309 310 return entry; 311 } 312 313 @Override 314 public LogEntry newLogEntry() { 315 return new LogEntryImpl(); 316 } 317 318 @Override 319 public abstract ExtendedInfo newExtendedInfo(Serializable value); 320 321 protected long syncLogCreationEntries(BaseLogEntryProvider provider, String repoId, String path, Boolean recurs) { 322 323 provider.removeEntries(DocumentEventTypes.DOCUMENT_CREATED, path); 324 CoreSession session = CoreInstance.getCoreSession(repoId); 325 DocumentRef rootRef = new PathRef(path); 326 DocumentModel root = guardedDocument(session, rootRef); 327 long nbAddedEntries = doSyncNode(provider, session, root, recurs); 328 329 log.debug("synced {} entries on {}", nbAddedEntries, path); 330 return nbAddedEntries; 331 } 332 333 protected long doSyncNode(BaseLogEntryProvider provider, CoreSession session, DocumentModel node, boolean recurs) { 334 335 long nbSyncedEntries = 1; 336 337 NuxeoPrincipal principal = session.getPrincipal(); 338 List<DocumentModel> folderishChildren = new ArrayList<>(); 339 340 provider.addLogEntry(doCreateAndFillEntryFromDocument(node, session.getPrincipal())); 341 342 for (DocumentModel child : guardedDocumentChildren(session, node.getRef())) { 343 if (child.isFolder() && recurs) { 344 folderishChildren.add(child); 345 } else { 346 provider.addLogEntry(doCreateAndFillEntryFromDocument(child, principal)); 347 nbSyncedEntries += 1; 348 } 349 } 350 351 if (recurs) { 352 for (DocumentModel folderChild : folderishChildren) { 353 nbSyncedEntries += doSyncNode(provider, session, folderChild, recurs); 354 } 355 } 356 357 return nbSyncedEntries; 358 } 359 360 @Override 361 @Deprecated 362 public void logEvents(EventBundle bundle) { 363 if (!isAuditable(bundle)) { 364 return; 365 } 366 for (Event event : bundle) { 367 logEvent(event); 368 } 369 } 370 371 protected boolean isAuditable(EventBundle eventBundle) { 372 for (String name : getAuditableEventNames()) { 373 if (eventBundle.containsEventName(name)) { 374 return true; 375 } 376 } 377 return false; 378 } 379 380 @Override 381 @Deprecated 382 public void logEvent(Event event) { 383 if (!getAuditableEventNames().contains(event.getName())) { 384 return; 385 } 386 LogEntry entry = buildEntryFromEvent(event); 387 if (entry == null) { 388 return; 389 } 390 if (Framework.isBooleanPropertyFalse(STREAM_AUDIT_ENABLED_PROP)) { 391 component.bulker.offer(entry); 392 } else { 393 log.error("Usage of AuditLogger#logEvent while AuditBulker is disabled", new Exception()); 394 } 395 } 396 397 @SuppressWarnings("resource") // LogManager not ours to close 398 @Override 399 public boolean await(long time, TimeUnit unit) throws InterruptedException { 400 if (Framework.isBooleanPropertyFalse(STREAM_AUDIT_ENABLED_PROP)) { 401 return component.bulker.await(time, unit); 402 } else { 403 StreamService service = Framework.getService(StreamService.class); 404 LogManager logManager = service.getLogManager(); 405 // when there is no lag between producer and consumer we are done 406 long deadline = System.currentTimeMillis() + unit.toMillis(time); 407 while (logManager.getLag(Name.ofUrn(STREAM_NAME), Name.ofUrn(COMPUTATION_NAME)).lag() > 0) { 408 if (System.currentTimeMillis() > deadline) { 409 return false; 410 } 411 Thread.sleep(50); 412 } 413 return true; 414 } 415 } 416 417 @Override 418 @Deprecated 419 public List<LogEntry> getLogEntriesFor(String uuid, Map<String, FilterMapEntry> filterMap, boolean doDefaultSort) { 420 // create builder 421 QueryBuilder builder = new AuditQueryBuilder(); 422 // create predicates 423 builder.predicate(Predicates.eq(LOG_DOC_UUID, uuid)); 424 filterMap.values().stream().map(this::convert).forEach(builder::and); 425 if (doDefaultSort) { 426 builder.defaultOrder(); 427 } 428 return queryLogs(builder); 429 } 430 431 protected Predicate convert(FilterMapEntry entry) { 432 String name = entry.getColumnName(); 433 String operator = entry.getOperator(); 434 Object value = entry.getObject(); 435 if (Operator.EQ.toString().equals(operator)) { 436 return Predicates.eq(name, value); 437 } else if (Operator.LT.toString().equals(operator)) { 438 return Predicates.lt(name, value); 439 } else if (Operator.LTEQ.toString().equals(operator)) { 440 return Predicates.lte(name, value); 441 } else if (Operator.GTEQ.toString().equals(operator)) { 442 return Predicates.gte(name, value); 443 } else if (Operator.GT.toString().equals(operator)) { 444 return Predicates.gt(name, value); 445 } else if (Operator.IN.toString().equals(operator)) { 446 return Predicates.in(name, (List<?>) value); 447 } 448 throw new NuxeoException(String.format("Audit backend search doesn't handle '%s' operator", operator)); 449 } 450 451 @Override 452 public List<LogEntry> queryLogsByPage(String[] eventIds, Date limit, String[] categories, String path, int pageNb, 453 int pageSize) { 454 QueryBuilder builder = new AuditQueryBuilder(); 455 if (ArrayUtils.isNotEmpty(eventIds)) { 456 if (eventIds.length == 1) { 457 builder.predicate(Predicates.eq(LOG_EVENT_ID, eventIds[0])); 458 } else { 459 builder.predicate(Predicates.in(LOG_EVENT_ID, eventIds[0])); 460 } 461 } 462 if (ArrayUtils.isNotEmpty(categories)) { 463 if (categories.length == 1) { 464 builder.predicate(Predicates.eq(LOG_CATEGORY, categories[0])); 465 } else { 466 builder.predicate(Predicates.in(LOG_CATEGORY, categories[0])); 467 } 468 } 469 if (path != null) { 470 builder.predicate(Predicates.eq(LOG_DOC_PATH, path)); 471 } 472 if (limit != null) { 473 builder.predicate(Predicates.lt(LOG_EVENT_DATE, limit)); 474 } 475 builder.offset(pageNb * pageSize).limit(pageSize); 476 return queryLogs(builder); 477 } 478 479 @Override 480 public long getLatestLogId(String repositoryId, String... eventIds) { 481 QueryBuilder builder = new AuditQueryBuilder().predicate(Predicates.eq(LOG_REPOSITORY_ID, repositoryId)) 482 .and(Predicates.in(LOG_EVENT_ID, eventIds)) 483 .order(OrderByExprs.desc(LOG_ID)) 484 .limit(1); 485 return queryLogs(builder).stream().mapToLong(LogEntry::getId).findFirst().orElse(0L); 486 } 487 488 @Override 489 public List<LogEntry> getLogEntriesAfter(long logIdOffset, int limit, String repositoryId, String... eventIds) { 490 QueryBuilder builder = new AuditQueryBuilder().predicate(Predicates.eq(LOG_REPOSITORY_ID, repositoryId)) 491 .and(Predicates.in(LOG_EVENT_ID, eventIds)) 492 .and(Predicates.gte(LOG_ID, logIdOffset)) 493 .order(OrderByExprs.asc(LOG_ID)) 494 .limit(limit); 495 return queryLogs(builder); 496 } 497 498 @Override 499 public void restore(AuditStorage auditStorage, int batchSize, int keepAlive) { 500 501 QueryBuilder builder = new AuditQueryBuilder(); 502 ScrollResult<String> scrollResult = auditStorage.scroll(builder, batchSize, keepAlive); 503 long t0 = System.currentTimeMillis(); 504 int total = 0; 505 506 log.info("Starting audit restoration"); 507 508 while (scrollResult.hasResults()) { 509 List<String> jsonEntries = scrollResult.getResults(); 510 log.debug("Appending {} entries", jsonEntries::size); 511 total += jsonEntries.size(); 512 append(jsonEntries); 513 514 double dt = (System.currentTimeMillis() - t0) / 1000.0; 515 if (dt != 0) { 516 log.debug("Restoration speed: {} entries/s", total / dt); 517 } 518 519 scrollResult = auditStorage.scroll(scrollResult.getScrollId()); 520 } 521 522 log.info("Audit restoration done: {} entries migrated from the audit storage", total); 523 524 } 525 526}