Source code

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.CoreInstance;
053import org.nuxeo.ecm.core.api.CoreSession;
054import org.nuxeo.ecm.core.api.DocumentModel;
055import org.nuxeo.ecm.core.api.DocumentModelList;
056import org.nuxeo.ecm.core.api.DocumentNotFoundException;
057import org.nuxeo.ecm.core.api.DocumentRef;
058import org.nuxeo.ecm.core.api.LifeCycleConstants;
059import org.nuxeo.ecm.core.api.NuxeoException;
060import org.nuxeo.ecm.core.api.NuxeoPrincipal;
061import org.nuxeo.ecm.core.api.PathRef;
062import org.nuxeo.ecm.core.api.PropertyException;
063import org.nuxeo.ecm.core.api.ScrollResult;
064import org.nuxeo.ecm.core.api.event.DocumentEventTypes;
065import org.nuxeo.ecm.core.api.security.SecurityConstants;
066import org.nuxeo.ecm.core.event.DeletedDocumentModel;
067import org.nuxeo.ecm.core.event.Event;
068import org.nuxeo.ecm.core.event.EventBundle;
069import org.nuxeo.ecm.core.event.EventContext;
070import org.nuxeo.ecm.core.event.impl.DocumentEventContext;
071import org.nuxeo.ecm.core.query.sql.model.Operator;
072import org.nuxeo.ecm.core.query.sql.model.Predicate;
073import org.nuxeo.ecm.platform.audit.api.AuditQueryBuilder;
074import org.nuxeo.ecm.platform.audit.api.AuditStorage;
075import org.nuxeo.ecm.platform.audit.api.ExtendedInfo;
076import org.nuxeo.ecm.platform.audit.api.FilterMapEntry;
077import org.nuxeo.ecm.platform.audit.api.LogEntry;
078import org.nuxeo.ecm.platform.audit.api.OrderByExprs;
079import org.nuxeo.ecm.platform.audit.api.Predicates;
080import org.nuxeo.ecm.platform.audit.impl.LogEntryImpl;
081import org.nuxeo.ecm.platform.audit.service.extension.AdapterDescriptor;
082import org.nuxeo.ecm.platform.audit.service.extension.AuditBackendDescriptor;
083import org.nuxeo.ecm.platform.audit.service.extension.ExtendedInfoDescriptor;
084import org.nuxeo.ecm.platform.el.ExpressionContext;
085import org.nuxeo.ecm.platform.el.ExpressionEvaluator;
086import org.nuxeo.lib.stream.log.LogManager;
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 Log log = LogFactory.getLog(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: " + exp + " on a DeletedDocumentModel, skipping.");
215                    }
216                    continue;
217                } catch (DocumentNotFoundException e) {
218                    if (!DocumentEventTypes.DOCUMENT_REMOVED.equals(entry.getEventId())) {
219                        log.error(String.format("Not found: %s, entry: %s", 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            Principal 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                String principalName;
271                if (principal instanceof NuxeoPrincipal) {
272                    principalName = ((NuxeoPrincipal) principal).getActingUser();
273                } else {
274                    principalName = principal.getName();
275                }
276                entry.setPrincipalName(principalName);
277            } else {
278                log.warn("received event " + eventName + " with null principal");
279            }
280            entry.setComment((String) properties.get("comment"));
281            if (document instanceof DeletedDocumentModel) {
282                entry.setComment("Document does not exist anymore!");
283            } else {
284                if (document.isLifeCycleLoaded()) {
285                    entry.setDocLifeCycle(document.getCurrentLifeCycleState());
286                }
287            }
288            if (LifeCycleConstants.TRANSITION_EVENT.equals(eventName)) {
289                entry.setDocLifeCycle((String) docCtx.getProperty(LifeCycleConstants.TRANSTION_EVENT_OPTION_TO));
290            }
291            String category = (String) properties.get("category");
292            if (category != null) {
293                entry.setCategory(category);
294            } else {
295                entry.setCategory("eventDocumentCategory");
296            }
297
298            doPutExtendedInfos(entry, docCtx, document, principal);
299
300        } else {
301            Principal principal = ctx.getPrincipal();
302            Map<String, Serializable> properties = ctx.getProperties();
303
304            if (principal != null) {
305                String principalName;
306                if (principal instanceof NuxeoPrincipal) {
307                    principalName = ((NuxeoPrincipal) principal).getActingUser();
308                } else {
309                    principalName = principal.getName();
310                }
311                entry.setPrincipalName(principalName);
312            }
313            entry.setComment((String) properties.get("comment"));
314
315            String category = (String) properties.get("category");
316            entry.setCategory(category);
317
318            doPutExtendedInfos(entry, ctx, null, principal);
319
320        }
321
322        return entry;
323    }
324
325    @Override
326    public LogEntry newLogEntry() {
327        return new LogEntryImpl();
328    }
329
330    @Override
331    public abstract ExtendedInfo newExtendedInfo(Serializable value);
332
333    protected long syncLogCreationEntries(BaseLogEntryProvider provider, String repoId, String path, Boolean recurs) {
334
335        provider.removeEntries(DocumentEventTypes.DOCUMENT_CREATED, path);
336        try (CoreSession session = CoreInstance.openCoreSession(repoId)) {
337            DocumentRef rootRef = new PathRef(path);
338            DocumentModel root = guardedDocument(session, rootRef);
339            long nbAddedEntries = doSyncNode(provider, session, root, recurs);
340
341            if (log.isDebugEnabled()) {
342                log.debug("synced " + nbAddedEntries + " entries on " + path);
343            }
344
345            return nbAddedEntries;
346        }
347    }
348
349    protected long doSyncNode(BaseLogEntryProvider provider, CoreSession session, DocumentModel node, boolean recurs) {
350
351        long nbSyncedEntries = 1;
352
353        Principal principal = session.getPrincipal();
354        List<DocumentModel> folderishChildren = new ArrayList<>();
355
356        provider.addLogEntry(doCreateAndFillEntryFromDocument(node, session.getPrincipal()));
357
358        for (DocumentModel child : guardedDocumentChildren(session, node.getRef())) {
359            if (child.isFolder() && recurs) {
360                folderishChildren.add(child);
361            } else {
362                provider.addLogEntry(doCreateAndFillEntryFromDocument(child, principal));
363                nbSyncedEntries += 1;
364            }
365        }
366
367        if (recurs) {
368            for (DocumentModel folderChild : folderishChildren) {
369                nbSyncedEntries += doSyncNode(provider, session, folderChild, recurs);
370            }
371        }
372
373        return nbSyncedEntries;
374    }
375
376    @Override
377    public void logEvents(EventBundle bundle) {
378        if (!isAuditable(bundle)) {
379            return;
380        }
381        for (Event event : bundle) {
382            logEvent(event);
383        }
384    }
385
386    protected boolean isAuditable(EventBundle eventBundle) {
387        for (String name : getAuditableEventNames()) {
388            if (eventBundle.containsEventName(name)) {
389                return true;
390            }
391        }
392        return false;
393    }
394
395    @Override
396    public void logEvent(Event event) {
397        if (!getAuditableEventNames().contains(event.getName())) {
398            return;
399        }
400        LogEntry entry = buildEntryFromEvent(event);
401        if (entry == null) {
402            return;
403        }
404        component.bulker.offer(entry);
405    }
406
407    @Override
408    public boolean await(long time, TimeUnit unit) throws InterruptedException {
409        if (Framework.isBooleanPropertyTrue(STREAM_AUDIT_ENABLED_PROP)) {
410            StreamService service = Framework.getService(StreamService.class);
411            LogManager logManager = service.getLogManager(DEFAULT_LOG_CONFIG);
412            // when there is no lag between producer and consumer we are done
413            long deadline = System.currentTimeMillis() + unit.toMillis(time);
414            while (logManager.getLag(STREAM_NAME, COMPUTATION_NAME).lag() > 0) {
415                if (System.currentTimeMillis() > deadline) {
416                    return false;
417                }
418                Thread.sleep(50);
419            }
420            return true;
421        } else {
422            return component.bulker.await(time, unit);
423        }
424    }
425
426    @Override
427    @Deprecated
428    public List<LogEntry> getLogEntriesFor(String uuid, Map<String, FilterMapEntry> filterMap, boolean doDefaultSort) {
429        // create builder
430        AuditQueryBuilder builder = new AuditQueryBuilder();
431        // create predicates
432        builder.addAndPredicate(Predicates.eq(LOG_DOC_UUID, uuid));
433        filterMap.values().stream().map(this::convert).forEach(builder::addAndPredicate);
434        if (doDefaultSort) {
435            builder.defaultOrder();
436        }
437        return queryLogs(builder);
438    }
439
440    protected Predicate convert(FilterMapEntry entry) {
441        String name = entry.getColumnName();
442        String operator = entry.getOperator();
443        Object value = entry.getObject();
444        if (Operator.EQ.toString().equals(operator)) {
445            return Predicates.eq(name, value);
446        } else if (Operator.LT.toString().equals(operator)) {
447            return Predicates.lt(name, value);
448        } else if (Operator.LTEQ.toString().equals(operator)) {
449            return Predicates.lte(name, value);
450        } else if (Operator.GTEQ.toString().equals(operator)) {
451            return Predicates.gte(name, value);
452        } else if (Operator.GT.toString().equals(operator)) {
453            return Predicates.gt(name, value);
454        } else if (Operator.IN.toString().equals(operator)) {
455            return Predicates.in(name, (List<?>) value);
456        }
457        throw new NuxeoException(String.format("Audit backend search doesn't handle '%s' operator", operator));
458    }
459
460    @Override
461    public List<LogEntry> queryLogsByPage(String[] eventIds, Date limit, String[] categories, String path, int pageNb,
462            int pageSize) {
463        AuditQueryBuilder builder = new AuditQueryBuilder();
464        if (ArrayUtils.isNotEmpty(eventIds)) {
465            if (eventIds.length == 1) {
466                builder.addAndPredicate(Predicates.eq(LOG_EVENT_ID, eventIds[0]));
467            } else {
468                builder.addAndPredicate(Predicates.in(LOG_EVENT_ID, eventIds[0]));
469            }
470        }
471        if (ArrayUtils.isNotEmpty(categories)) {
472            if (categories.length == 1) {
473                builder.addAndPredicate(Predicates.eq(LOG_CATEGORY, categories[0]));
474            } else {
475                builder.addAndPredicate(Predicates.in(LOG_CATEGORY, categories[0]));
476            }
477        }
478        if (path != null) {
479            builder.addAndPredicate(Predicates.eq(LOG_DOC_PATH, path));
480        }
481        if (limit != null) {
482            builder.addAndPredicate(Predicates.lt(LOG_EVENT_DATE, limit));
483        }
484        builder.offset(pageNb * pageSize).limit(pageSize);
485        return queryLogs(builder);
486    }
487
488    @Override
489    public long getLatestLogId(String repositoryId, String... eventIds) {
490        AuditQueryBuilder builder = new AuditQueryBuilder().addAndPredicate(
491                Predicates.eq(LOG_REPOSITORY_ID, repositoryId))
492                                                           .addAndPredicate(Predicates.in(LOG_EVENT_ID, eventIds))
493                                                           .order(OrderByExprs.desc(LOG_ID))
494                                                           .limit(1);
495        return queryLogs(builder).stream().mapToLong(LogEntry::getId).findFirst().orElse(0L);
496    }
497
498    @Override
499    public List<LogEntry> getLogEntriesAfter(long logIdOffset, int limit, String repositoryId, String... eventIds) {
500        AuditQueryBuilder builder = new AuditQueryBuilder().addAndPredicate(
501                Predicates.eq(LOG_REPOSITORY_ID, repositoryId))
502                                                           .addAndPredicate(Predicates.in(LOG_EVENT_ID, eventIds))
503                                                           .addAndPredicate(Predicates.gte(LOG_ID, logIdOffset))
504                                                           .order(OrderByExprs.asc(LOG_ID))
505                                                           .limit(limit);
506        return queryLogs(builder);
507    }
508
509    @Override
510    public void restore(AuditStorage auditStorage, int batchSize, int keepAlive) {
511
512        AuditQueryBuilder builder = new AuditQueryBuilder();
513        ScrollResult<String> scrollResult = auditStorage.scroll(builder, batchSize, keepAlive);
514        long t0 = System.currentTimeMillis();
515        int total = 0;
516
517        log.info("Starting audit restoration");
518
519        while (scrollResult.hasResults()) {
520            List<String> jsonEntries = scrollResult.getResults();
521            total += jsonEntries.size();
522            append(jsonEntries);
523
524            double dt = (System.currentTimeMillis() - t0) / 1000.0;
525            if (dt != 0) {
526                if (log.isDebugEnabled()) {
527                    log.debug("Restoration speed: " + (total / dt) + " entries/s");
528                }
529            }
530
531            scrollResult = auditStorage.scroll(scrollResult.getScrollId());
532        }
533
534        log.info("Audit restoration done: " + total + " entries migrated from the audit storage");
535
536    }
537
538}