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