Java tutorial
/** * OLAT - Online Learning and Training<br> * http://www.olat.org * <p> * Licensed under the Apache License, Version 2.0 (the "License"); <br> * you may not use this file except in compliance with the License.<br> * You may obtain a copy of the License at * <p> * http://www.apache.org/licenses/LICENSE-2.0 * <p> * Unless required by applicable law or agreed to in writing,<br> * software distributed under the License is distributed on an "AS IS" BASIS, <br> * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. <br> * See the License for the specific language governing permissions and <br> * limitations under the License. * <p> * Copyright (c) 1999-2009 at Multimedia- & E-Learning Services (MELS),<br> * University of Zurich, Switzerland. * <p> */ package org.olat.core.logging.activity; import java.io.PrintWriter; import java.io.StringWriter; import java.io.UnsupportedEncodingException; import java.io.Writer; import java.lang.reflect.InvocationTargetException; import java.util.ArrayList; import java.util.Date; import java.util.Iterator; import java.util.LinkedList; import java.util.List; import java.util.Locale; import java.util.Set; import javax.servlet.http.HttpServletRequest; import org.hibernate.FlushMode; import org.olat.core.commons.persistence.DB; import org.olat.core.commons.persistence.DBFactory; import org.olat.core.commons.persistence.DBQuery; import org.olat.core.gui.control.Controller; import org.olat.core.gui.control.WindowControl; import org.olat.core.id.Identity; import org.olat.core.id.context.ContextEntry; import org.olat.core.id.context.StackedBusinessControl; import org.olat.core.logging.OLog; import org.olat.core.logging.Tracing; import org.olat.core.util.UserSession; import org.olat.core.util.i18n.I18nManager; /** * Default implementation of the IUserActivityLogger which logs into the o_loggingtable. * <p> * This class would usually not be subclassed or changed as it closely works together with the ThreadLocalUserActivityLogger. * <p> * Also, this class should not have to be accessed directly or cast to in any way. * <p> * There is an instance of UserActivityLoggerImpl for every Controller and for every ThreadLocalUserActivityLogger during its run methods. * <p> * The UserActivityLoggerImpl gathers all information during the course of time to be ready for the log() call later - i.e. to have all mandatory information at that * time. This includes such things as session/identity, the businessPath and the list of LoggingResourceables. * <p> * Also, this class implements the simpleDuration calculation - which is a simple time difference between log calls within a session. Note that this is really simple, as * it does not distinguish between having multiple log calls per click and having no log calls for a number of clicks - hence the simpleDuration can only be useful to * some extend. The plan is to introduce a semanticDuration or some other concept later. Anyway, for the simpleDuration the UserActivityLoggerImpl stores the last * LoggingObject (the actual hibernate object) into the session for comparison later. * <p> * <P> * Initial Date: 21.10.2009 <br> * * @author Stefan */ public class UserActivityLoggerImpl implements IUserActivityLogger { /** the logging object used in this class **/ private static final OLog log_ = Tracing.createLoggerFor(UserActivityLoggerImpl.class); /** the key with which the last LoggingObject is stored in the session - used for simpleDuration calculation only **/ public static final String USESS_KEY_USER_ACTIVITY_LOGGING_LAST_LOG = "USER_ACTIVITY_LOGGING_LAST_LOG"; /** the session - which this UserActivityLoggerImpl should later log into the database **/ private UserSession session_; /** if isLogAnonymous equal to true and if resourceAdminAction equal to false then anonymize log entries **/ private boolean isLogAnonymous_ = LogModule.isLogAnonymous(); /** if not null this stickyActionType_ overwrites whatever comes as the ActionType in the ILoggingAction in log() **/ private ActionType stickyActionType_ = null; /** set user properties which needed for logging **/ private Set<String> userProperties_ = LogModule.getUserProperties(); /** the identity - which this UserActivityLoggerImpl should later log into the database **/ private Identity identity_; /** * the list of LoggingResourceable objects which have been added to this UserActivityLoggerImpl yet - all used later for logging into the database */ private List<ILoggingResourceable> resourceableList_ = null; /** * the current businessPath - this is used for making validity checks against. * <p> * The idea is to eventually achieve a complete match between LoggingResourceable and businessPath. While we are currently miles away from this, when it eventually * matches we could get rid of one or the other and only use for example the businessPath, i.e. the underlying contextEntries (which contain the actual * OlatResourceable objects). The problem though always seems to remain that not all information which we would like to log is actually a OlatResourceable - sometimes * it's as simple as a String (i.e. number of qti attemts etc) which we'll never convert to an OlatResourceable. Anyway, once we'd have a 100% correct businessPath * match with the loggingResourceables (at least, lets say the OlatResourceables thereof) we could simplify things here a lot */ private String businessPath_; /** @see #businessPath_ **/ private List<ContextEntry> bcContextEntries_; /** * whether or not this UserActivityLoggerImpl should propagate setters to businessPath and bcContextEntries_ to the runtimeParent. * <p> * This is needed for the following reason: there are two kinds of usages for the ThreadLocalUserActivityLogger: * <ul> * <li>It can happen that during an event() call a LoggingResourceable is set on the ThreadLocalUserActivityLogger which is needed lateron in the rendering - or in * other parts which are outside the original event() method. I.e. there should be a propagation mechanism where LoggingResourceables propagate to the current * parent-chaing of ThreadLocalUserActivityLoggers</li> * <li>During the simplevm eventbus handling though, we want to make sure that nothing propagates back to the caller - since we're simulating basically a new thread * calling an event handler - but of course that event handler could make changes to the ThreadLocalUserActivityLogger - for example by adding a LoggingResourceable - * this information we do not want to propagate</li> * </ul> * Hence this field controls whether or not information propagates to runtime parent ThreadLocalUserActivityLoggers or not */ private final boolean propageToThreadLocal_; /** * The runtime parent UserActivityLoggerImpl. * <p> * This is always set except for initial creation in the OLATServlet. * <p> * The runtime parent is used to propagate LoggingResourceables and businessPath/contextEntries. The reason for this structure is to be able to take a Controller's * IUserActivityLogger during the event call, set it as ThreadLocalUserActivityLogger and still have the parent (i.e. the IUserActivityLogger which was set by the * time the event method was called) also be informed about changes. This is because there are situations where we do logging after the event method (i.e. during * rendering) and need to have the LoggingResourceables as well as the businessPath/contextEntries. * <p> * This is very deep framework. */ private UserActivityLoggerImpl runtimeParent_; /** * package protected constructor of the UserActivityLoggerImpl based on a HttpServletRequest - out of which the session and identity are extracted. * <p> * This is used to set up a UserActivityLoggerImpl initially by OLATServlet.doPost and OLATServlet.init() * <p> * * @param hReq the HttpServletRequest out of which the session and identity are extracted */ UserActivityLoggerImpl(HttpServletRequest hReq) { propageToThreadLocal_ = false; runtimeParent_ = null; initWithRequest(hReq); } /** * Internal initialization method for the OLATServlet.doPost case * * @param hReq the HttpServletRequest out of which the session and identity are extracted */ private void initWithRequest(HttpServletRequest hReq) { if (hReq == null) { throw new IllegalArgumentException("hReq must not be null"); } session_ = UserSession.getUserSessionIfAlreadySet(hReq); if (session_ != null) { identity_ = session_.getIdentity(); } if (session_ == null) { System.out.println("session is null"); } } /** * package protected constructor of the UserActivityLoggerImpl * <p> * This is used to set up a UserActivityLoggerImpl initially by OLATServlet.init() */ UserActivityLoggerImpl() { propageToThreadLocal_ = false; runtimeParent_ = null; } private UserActivityLoggerImpl(IUserActivityLogger userActivityLogger, WindowControl wControl, boolean propageToThreadLocal) { if (userActivityLogger == null) { throw new IllegalArgumentException("userActivityLogger must not be null"); } if (!(userActivityLogger instanceof UserActivityLoggerImpl)) { // currently we require the userActivityLogger to be UserActivityLoggerImpl // the reason for this is that we do direct field accesses - which would otherwise // have to be added to the IUserActivityLogger interface (making it less clean) // or by having a IUserActivityLogger.getFieldAccessor() of some sort which // would then achieve the same thing. // For the current purpose of User Activity Logging run, there is no // need to support other implementator yet - it is not nice though, agreed. throw new IllegalArgumentException( "userActivityLogger other than UserActivityLoggerImpl not yet supported: " + userActivityLogger.getClass()); } final UserActivityLoggerImpl bluePrint = (UserActivityLoggerImpl) userActivityLogger; // initialize fields propageToThreadLocal_ = propageToThreadLocal; // copy field values from the blueprint session_ = bluePrint.session_; identity_ = bluePrint.identity_; stickyActionType_ = bluePrint.stickyActionType_; resourceableList_ = bluePrint.resourceableList_ == null ? null : new LinkedList<ILoggingResourceable>(bluePrint.resourceableList_); // get the businessPath from the windowControl if possible String businessPath = null; if (wControl != null && wControl.getBusinessControl() != null) { if (wControl.getBusinessControl() instanceof StackedBusinessControl) { StackedBusinessControl sbc = (StackedBusinessControl) wControl.getBusinessControl(); final List<ContextEntry> ces = sbc.getContextEntryStack(); bcContextEntries_ = ces != null ? new LinkedList<ContextEntry>(ces) : null; } businessPath = wControl.getBusinessControl().getAsString(); } if (businessPath != null && businessPath.length() != 0) { businessPath_ = businessPath; if (propageToThreadLocal) { ThreadLocalUserActivityLogger.setBusinessPath(businessPath, this); ThreadLocalUserActivityLogger.setBCContextEntries(bcContextEntries_, this); } } else { businessPath_ = bluePrint.businessPath_; bcContextEntries_ = bluePrint.bcContextEntries_; } } /** * This method is used by the DefaultController to setup a new logger based on what's currently set in the ThreadLocalUserActivityLogger. * * @param wControl the WindowControl from which the businessPath and contextEntries are extracted * @return a new UserActivityLoggerImpl purpose built for the DefaultController - never returns null */ public static UserActivityLoggerImpl setupLoggerForController(WindowControl wControl) { final IUserActivityLogger threadLocalUserActivityLogger = ThreadLocalUserActivityLogger .getUserActivityLogger(); if (!(threadLocalUserActivityLogger instanceof UserActivityLoggerImpl)) { throw new IllegalStateException( "threadLocalUserActivityLogger must be of type GenericUserActivityLogger"); } final UserActivityLoggerImpl genUserActivityLogger = (UserActivityLoggerImpl) threadLocalUserActivityLogger; final UserActivityLoggerImpl newLogger = new UserActivityLoggerImpl(genUserActivityLogger, wControl, true); newLogger.runtimeParent_ = genUserActivityLogger; return newLogger; } /** * This method is used by ThreadLocalUserActivityLogger for runtime setup during event handling * * @param userActivityLogger the "blue print" UserActivityLogger which should be copied for runtime use * @return a new UserActivityLoggerImpl purpose built for runtime use */ static UserActivityLoggerImpl copyLoggerForRuntime(IUserActivityLogger userActivityLogger) { if (userActivityLogger == null) { throw new IllegalArgumentException("userActivityLogger must not be null"); } final IUserActivityLogger threadLocalUserActivityLogger = ThreadLocalUserActivityLogger .getUserActivityLogger(); if (!(threadLocalUserActivityLogger instanceof UserActivityLoggerImpl)) { throw new IllegalStateException( "threadLocalUserActivityLogger must be of type GenericUserActivityLogger"); } final UserActivityLoggerImpl genUserActivityLogger = (UserActivityLoggerImpl) threadLocalUserActivityLogger; final UserActivityLoggerImpl newLogger = new UserActivityLoggerImpl(userActivityLogger, null, true); newLogger.runtimeParent_ = genUserActivityLogger; return newLogger; } /** * Webcontainer thread for expired sessions triggers value unbound which in turn disposes the whole gui session. This UserTrackingLogger must be specially rooted. * * @return */ public static IUserActivityLogger newLoggerForValueUnbound(UserSession session) { // // propagate is set to true - ValueUnbound triggers dispose // after dispose is done, UserSession must clean up // IUserActivityLogger ual = ThreadLocalUserActivityLogger.getUserActivityLogger(); UserActivityLoggerImpl newLogger = new UserActivityLoggerImpl(ual, null, true); // Note: can't use frameworkSetSession here as that one might complain about // no threadlocal useractivitylogger being set - but actually, what we // want to do here is to just initialize the newLogger without any side-effects newLogger.session_ = session; return newLogger; } /** * The special thing about this 'logger for EventBus' is, that it doesn't propagate resourceInfos/businessPath etc to the parent nor the * ThreadLocalUserActivityLogger. * <p> * * @param controller the Controller from which the IUserActivityLogger and the WindowControl (businessPath) should be extracted * @return a new UserActivityLoggerImpl purpose built for use by the EventBus during fireEvent */ public static UserActivityLoggerImpl newLoggerForEventBus(Controller controller) { IUserActivityLogger logger = controller.getUserActivityLogger(); WindowControl wControl = controller.getWindowControlForDebug(); UserActivityLoggerImpl newLogger = new UserActivityLoggerImpl(logger, wControl, false); newLogger.frameworkSetBusinessPathFromWindowControl(controller.getWindowControlForDebug()); return newLogger; // don't set runtimeParent ! } @Override public void frameworkSetSession(UserSession session) { if (session_ == session) { return; } session_ = session; if (runtimeParent_ != null) { runtimeParent_.frameworkSetSession(session); } IUserActivityLogger threadLocalUserActivityLogger = ThreadLocalUserActivityLogger.getUserActivityLogger(); if (propageToThreadLocal_ && runtimeParent_ != threadLocalUserActivityLogger) { threadLocalUserActivityLogger.frameworkSetSession(session); } } /** * Internal getter for the resourceableList - initializes the list if it's null * * @return the resourcableList - initializes the list if it's null */ private List<ILoggingResourceable> getLoggingResourceableList() { if (resourceableList_ == null) { resourceableList_ = new LinkedList<ILoggingResourceable>(); } return resourceableList_; } @Override public void addLoggingResourceInfo(ILoggingResourceable loggingResourceable) { if (loggingResourceable == null) { throw new IllegalArgumentException("resourceInfo must not be null"); } int existingPos = getLoggingResourceableList().indexOf(loggingResourceable); if (existingPos != -1) { ILoggingResourceable existingRI = getLoggingResourceableList().get(existingPos); if (existingRI.getName() != null && loggingResourceable.getName() != null && existingRI.getName().equals(loggingResourceable.getName())) { // ignore - already set return; } else if (existingRI.getName() == null && loggingResourceable.getName() == null) { // both names are null and we otherwiese assume that they are equal // so ignore them return; } // otherwise we have a matching resourceInfo already registered (same type,id) but with a different name // let's update it getLoggingResourceableList().remove(existingPos); } getLoggingResourceableList().add(loggingResourceable); if (runtimeParent_ != null) { runtimeParent_.addLoggingResourceInfo(loggingResourceable); } IUserActivityLogger threadLocalUserActivityLogger = ThreadLocalUserActivityLogger.getUserActivityLogger(); if (propageToThreadLocal_ && runtimeParent_ != threadLocalUserActivityLogger) { threadLocalUserActivityLogger.addLoggingResourceInfo(loggingResourceable); } } @Override public void frameworkSetBusinessPath(String businessPath) { if (businessPath == businessPath_ || businessPath == null || businessPath.length() == 0 || (businessPath_ != null && businessPath.length() < businessPath_.length())) { return; } if (businessPath != null) { this.businessPath_ = businessPath; } if (runtimeParent_ != null) { runtimeParent_.frameworkSetBusinessPath(businessPath); } IUserActivityLogger threadLocalUserActivityLogger = ThreadLocalUserActivityLogger.getUserActivityLogger(); if (propageToThreadLocal_ && runtimeParent_ != threadLocalUserActivityLogger) { threadLocalUserActivityLogger.frameworkSetBusinessPath(businessPath); } } @Override public void frameworkSetBCContextEntries(List<ContextEntry> bcEntries) { if (bcContextEntries_ == bcEntries || bcEntries == null || bcEntries.size() == 0 || (bcContextEntries_ != null && bcEntries.size() < bcContextEntries_.size())) { return; } if (bcEntries != null) { this.bcContextEntries_ = bcEntries; } if (runtimeParent_ != null) { runtimeParent_.frameworkSetBCContextEntries(bcEntries); } IUserActivityLogger threadLocalUserActivityLogger = ThreadLocalUserActivityLogger.getUserActivityLogger(); if (propageToThreadLocal_ && runtimeParent_ != threadLocalUserActivityLogger) { threadLocalUserActivityLogger.frameworkSetBCContextEntries(bcEntries); } } @Override public void frameworkSetBusinessPathFromWindowControl(WindowControl wControl) { if (wControl != null && wControl.getBusinessControl() != null) { if (wControl.getBusinessControl() instanceof StackedBusinessControl) { StackedBusinessControl sbc = (StackedBusinessControl) wControl.getBusinessControl(); final List<ContextEntry> ces = sbc.getContextEntryStack(); if (ces != null) { frameworkSetBCContextEntries(new LinkedList<ContextEntry>(ces)); } } final String bp = wControl.getBusinessControl().getAsString(); frameworkSetBusinessPath(bp); } } /** * Returns the combined and orderd list of LoggingResourceables which are set on this UserActivityLoggerImpl and are matching the contextEntries. * <p> * Note that this method fails if there is a contextEntry which doesn't have a corresponding LoggingResourceable: This would be a situation where the * businessPath/contextEntry has a resource defined which is unknown to this UserActivityLoggerImpl - i.e. which has not been set by the Controller or not been passed * via the log() call. * <p> * The safety check with the LoggingAction's ResourceableTypeList is not done in this method. * * @param lriOrNull an * @return the combined and ordered list of LoggingResourceables which should go right to the database in the corresponding fields */ private List<ILoggingResourceable> getCombinedOrderedLoggingResourceables( ILoggingResourceable... additionalLoggingResourceables) { List<ILoggingResourceable> result = new LinkedList<ILoggingResourceable>(); List<ILoggingResourceable> inputCopy = new LinkedList<ILoggingResourceable>(getLoggingResourceableList()); if (additionalLoggingResourceables != null) { for (int i = 0; i < additionalLoggingResourceables.length; i++) { ILoggingResourceable additionalLoggingResourceable = additionalLoggingResourceables[i]; int existingPos = inputCopy.indexOf(additionalLoggingResourceable); if (existingPos != -1) { ILoggingResourceable existingRI = getLoggingResourceableList().get(existingPos); if (existingRI.getName() != null && additionalLoggingResourceable.getName() != null && existingRI.getName().equals(additionalLoggingResourceable.getName())) { // ignore - already set continue; } else if (existingRI.getName() == null && additionalLoggingResourceable.getName() == null) { // both names are null and we otherwiese assume that they are equal // so ignore them continue; } // otherwise we have a matching resourceInfo already registered (same type,id) but with a different name // let's update it inputCopy.remove(existingPos); } inputCopy.add(additionalLoggingResourceable); } } if (bcContextEntries_ != null) { LinkedList<ContextEntry> bcContextEntriesCopy = new LinkedList<ContextEntry>(); for (Iterator<ContextEntry> it = bcContextEntries_.iterator(); it.hasNext();) { ContextEntry ce = it.next(); if (!bcContextEntriesCopy.contains(ce)) { bcContextEntriesCopy.add(ce); } } for (Iterator<ContextEntry> it = bcContextEntriesCopy.iterator(); it.hasNext();) { ContextEntry ce = it.next(); boolean foundIt = false; for (Iterator<ILoggingResourceable> it2 = inputCopy.iterator(); it2.hasNext();) { ILoggingResourceable resourceInfo = it2.next(); if (resourceInfo.correspondsTo(ce)) { // perfecto result.add(resourceInfo); it2.remove(); foundIt = true; break; } } if (!foundIt) { String oresourceableOres = "n/a (null)"; if (ce != null && ce.getOLATResourceable() != null) { try { java.lang.reflect.Method getOlatResource = ce.getOLATResourceable().getClass() .getDeclaredMethod("getOlatResource"); if (getOlatResource != null) { oresourceableOres = String .valueOf(getOlatResource.invoke(ce.getOLATResourceable())); } } catch (SecurityException e) { log_.error("SecurityException while retrieving getOlatResource() Method from " + ce.getOLATResourceable().getClass()); } catch (NoSuchMethodException e) { log_.info( "(OK) ContextEntry's OLATResourceable had no further getOlatResource() method: " + ce.getOLATResourceable().getClass()); } catch (IllegalArgumentException e) { log_.error("IllegalArgumentException while calling getOlatResource() Method from " + ce.getOLATResourceable().getClass(), e); } catch (IllegalAccessException e) { log_.error("IllegalAccessException while calling getOlatResource() Method from " + ce.getOLATResourceable().getClass(), e); } catch (InvocationTargetException e) { log_.error("IllegalAccessException while calling getOlatResource() Method from " + ce.getOLATResourceable().getClass(), e); } } log_.info("Could not find any LoggingResourceable corresponding to this ContextEntry: " + ce.toString() + ", ce.getOLATResourceable()=" + ce.getOLATResourceable() + ", ce.getOLATResourceable().getOlatResource()=" + oresourceableOres + ", dump of resource infos:"); for (Iterator<ILoggingResourceable> it2 = inputCopy.iterator(); it2.hasNext();) { ILoggingResourceable resourceInfo = it2.next(); log_.info("id: " + resourceInfo.getId() + ", name=" + resourceInfo.getName() + ", type=" + resourceInfo.getType() + ", toString: " + resourceInfo.toString()); } log_.error( "Could not find any LoggingResourceable corresponding to this ContextEntry: " + ce.toString(), new Exception("UserActivityLoggerImpl.getCombinedOrderedLoggingResourceables()")); } } } if (inputCopy.size() != 0) { // otherwise we have an inconsistency // just add all the remaining from inputCopy to result // no idea about the ordering - but the inputCopy has some sort of useful ordering as well, presumably result.addAll(inputCopy); } return result; } @Override public void setStickyActionType(ActionType actionType) { stickyActionType_ = actionType; } @Override public ActionType getStickyActionType() { return stickyActionType_; } @Override public void log(ILoggingAction loggingAction, Class<?> callingClass, ILoggingResourceable... lriOrNull) { final ActionType actionType = stickyActionType_ != null ? stickyActionType_ : loggingAction.getResourceActionType(); // don't log entries with loggingAction type 'tracking' if (isLogAnonymous_ && actionType.equals(ActionType.tracking)) { return; } // fetch some of the loggingAction fields - used for error logging below final CrudAction crudAction = loggingAction.getCrudAction(); final ActionVerb actionVerb = loggingAction.getActionVerb(); final String actionObject = loggingAction.getActionObject(); // calculate the combined and ordered list of LoggingResourceables which should go // to the database below right away List<ILoggingResourceable> resourceInfos = getCombinedOrderedLoggingResourceables(lriOrNull); if (loggingAction.getTypeListDefinition() == null) { // this is a foul! log_.warn("LoggingAction has no ResourceableTypeList defined: action=" + loggingAction + ", fieldId=" + loggingAction.getJavaFieldIdForDebug()); } else { // good boy String errorMsg = loggingAction.getTypeListDefinition().executeCheckAndGetErrorMessage(resourceInfos); if (errorMsg != null) { // we found an inconsistency // lets make this a warn log_.warn( "LoggingAction reported an inconsistency: " + loggingAction.getActionVerb() + " " + loggingAction.getActionObject() + ", action=" + loggingAction + ", fieldId=" + loggingAction.getJavaFieldIdForDebug() + ", expected: " + loggingAction.getTypeListDefinition().toString() + ", actual: " + convertLoggingResourceableListToString(resourceInfos), new Exception("OLAT-4653")); } } if (session_ == null) { // then I can't log - log information without session/user information isn't of much use // issue a log warn with a stacktrace for this log_.error("No session available to UserActivityLogger. Cannot write log entry: " + crudAction.name() + ":" + actionVerb.name() + ", " + actionObject + ", " + convertLoggingResourceableListToString(resourceInfos), new Exception()); return; } if (session_.getSessionInfo() == null || session_.getSessionInfo().getSession() == null || session_.getSessionInfo().getSession().getId() == null || session_.getSessionInfo().getSession().getId().length() == 0) { // no session Id available - odd log_.error("No session information available to UserActivityLogger. Cannot write log entry: " + crudAction.name() + ":" + actionVerb.name() + ", " + actionObject + ", " + convertLoggingResourceableListToString(resourceInfos), new Exception()); return; } final String sessionId = session_.getSessionInfo().getSession().getId(); Identity identity = session_.getIdentity(); if (identity == null) { // no identity available - odd log_.error("No identity available to UserActivityLogger. Cannot write log entry: " + crudAction.name() + ":" + actionVerb.name() + ", " + actionObject + ", " + convertLoggingResourceableListToString(resourceInfos), new Exception()); return; } Long identityKey = identity.getKey(); if (actionType != ActionType.admin) { final String identityKeyStr = String.valueOf(identityKey); for (Iterator it = resourceInfos.iterator(); it.hasNext();) { ILoggingResourceable lr = (ILoggingResourceable) it.next(); if (lr.getResourceableType() == StringResourceableType.targetIdentity) { if (log_.isDebug() && !lr.getId().equals(identityKeyStr)) { // complain final Writer strackTraceAsStringWriter = new StringWriter(); final PrintWriter printWriter = new PrintWriter(strackTraceAsStringWriter); (new Exception("OLAT-4955 debug stacktrac")).printStackTrace(printWriter); log_.debug( "OLAT-4955: Not storing targetIdentity for non-admin logging actions. A non-admin logging action wanted to store a user other than the one from the session: action=" + loggingAction + ", fieldId=" + loggingAction.getJavaFieldIdForDebug(), strackTraceAsStringWriter.toString()); } // OLAT-4955: remove targetIdentity it.remove(); } } } String identityName; if (isLogAnonymous_ && (actionType != ActionType.admin)) { identityName = ""; } else { identityName = identity.getName(); } // start creating the LoggingObject final LoggingObject logObj = new LoggingObject(sessionId, identityKey, identityName, crudAction.name().substring(0, 1), actionVerb.name(), actionObject); // do simpleDuration calculation & storing LoggingObject lastLogObj = (LoggingObject) session_.getEntry(USESS_KEY_USER_ACTIVITY_LOGGING_LAST_LOG); if (lastLogObj != null) { // lastLogObj = (LoggingObject) DBFactory.getInstance().loadObject(lastLogObj); // DBFactory.getInstance().updateObject(lastLogObj); // Implementation Note: // we used to do loadObject(), updateObject() here - which is the preferred best practice hibernate way // for changing an existing object in the database. // in the setup @UZH we'll use BLACKHOLE as the storage engine for the o_loggingtable (this is to have // minimal work load on the Main OLAT DB and not have duplicate data on the Main OLAT DB and the Logging DB). // Using BLACKHOLE results in the 'lastLogObj' here, not to exist in the database anymore. // Hence we can't do a loadObject() nor an updateObject(). The latter does not work due to the fact // that Hibernate checks the number of updated rows and expect that to equal 1 - which is not the case // when using BLACKHOLE. // Workaround: - also compare with LoggingObject.hbm.xml docu // // We use the sql-update's feature check="none", which disables the above mentioned check. // Using this in combination with manual SQL code below seems to be the only feasible way // to have Hibernate not do any row-number-checks. // Implications of the workaround: // // * Manual SQL: It shouldn't be a big deal to have this manual SQL code as it is very standard. // * CANT USE updateObject(LoggingObject) EVER: // @TODO We might have to add a check which verifies that no one calls updateObject(LoggingObject) // if that would be called it would simply fail in the BLACKHOLE@UZH setup // calculate the duration - take the simple diff of the two creationDate fields Date currentTime = logObj.getCreationDate(); Date lastTime = lastLogObj.getCreationDate(); long duration; if (lastTime == null) { duration = -1; } else if (currentTime == null) { duration = System.currentTimeMillis() - lastTime.getTime(); } else { duration = currentTime.getTime() - lastTime.getTime(); } DB db = DBFactory.getInstanceForClosing(); if (db != null && db.isError()) { // then we would run into an ERROR when we'd do more with this DB // hence we just issue a log.info here with the details // @TODO: lower to log_.info once we checked that it doesn't occur very often (best for 6.4) log_.warn( "log: DB is in Error state therefore the UserActivityLoggerImpl cannot update the simpleDuration of log_id " + lastLogObj.getKey() + " with value " + duration + ", loggingObject: " + lastLogObj); } else { DBQuery update = DBFactory.getInstance().createQuery( "update org.olat.core.logging.activity.LoggingObject set simpleDuration = :duration where log_id = :logid"); update.setLong("duration", duration); update.setLong("logid", lastLogObj.getKey()); // we have to do FlushMode.AUTO (which is the default anyway) update.executeUpdate(FlushMode.AUTO); } } // store the current logging object in the session - for duration calculation at next log session_.putEntry(USESS_KEY_USER_ACTIVITY_LOGGING_LAST_LOG, logObj); if (resourceInfos != null && resourceInfos.size() != 0) { // this should be the normal case - we do have LoggingResourceables which we can log // alongside the log message // check if we have more than 4 - if we do, issue a log and remove the middle ones if (resourceInfos.size() > 4) { log_.warn("More than 4 resource infos set on a user activity log. Can only have 4. Having: " + resourceInfos.size()); int diff = resourceInfos.size() - 4; for (int i = 0; i < diff; i++) { resourceInfos.remove(3); } } // get the target resourceable ILoggingResourceable ri = resourceInfos.get(resourceInfos.size() - 1); logObj.setTargetResourceInfo(ri); // now set parent - if applicable if (resourceInfos.size() > 1) { ri = resourceInfos.get(resourceInfos.size() - 2); logObj.setParentResourceInfo(ri); } // and set the grand parent - if applicable if (resourceInfos.size() > 2) { ri = resourceInfos.get(resourceInfos.size() - 3); logObj.setGrandParentResourceInfo(ri); } // and set the great grand parent - if applicable if (resourceInfos.size() > 3) { ri = resourceInfos.get(resourceInfos.size() - 4); logObj.setGreatGrandParentResourceInfo(ri); } } // fill the remaining fields logObj.setBusinessPath(businessPath_); logObj.setSourceClass(callingClass.getCanonicalName()); logObj.setSimpleDuration(-1); logObj.setResourceAdminAction(actionType.equals(ActionType.admin) ? true : false); Locale locale = I18nManager.getInstance() .getLocaleOrDefault(identity.getUser().getPreferences().getLanguage()); // prepate the user properties, set them at once List<String> tmpUserProperties = new ArrayList<String>(12); for (Iterator<String> iterator = userProperties_.iterator(); iterator.hasNext();) { String userPropString = identity.getUser().getPropertyOrIdentityEnvAttribute(iterator.next(), locale); boolean shorten = false; try { if (userPropString != null && userPropString.getBytes("UTF-8").length > 254) { shorten = true; } } catch (UnsupportedEncodingException uee) { log_.error("error while calculating real string length: unsupported encoding: ", uee); shorten = true; } if (shorten) { log_.error( "Userproperty was too long for logging-table (shortened automatically). check that nothing valueable is lost! value before cut: " + userPropString); userPropString = userPropString.substring(0, 255); } tmpUserProperties.add(userPropString); } logObj.setUserProperties(tmpUserProperties); // and store it DB db = DBFactory.getInstanceForClosing(); if (db != null && db.isError()) { // then we would run into an ERROR when we'd do more with this DB // hence we just issue a log.info here with the details // @TODO: lower to log_.info once we checked that it doesn't occur very often (best for 6.4) log_.warn( "log: DB is in Error state therefore the UserActivityLoggerImpl cannot store the following logging action into the loggingtable: " + logObj); } else { DBFactory.getInstance().saveObject(logObj); } } /** toString for debug **/ private String convertLoggingResourceableListToString(List<ILoggingResourceable> resourceInfos) { StringBuffer loggingResourceableListToString = new StringBuffer("[LoggingResourceables: "); loggingResourceableListToString.append(resourceInfos.size()); for (Iterator<ILoggingResourceable> iterator = resourceInfos.iterator(); iterator.hasNext();) { ILoggingResourceable loggingResourceable = iterator.next(); loggingResourceableListToString.append(", "); loggingResourceableListToString.append(loggingResourceable); } loggingResourceableListToString.append("]"); return loggingResourceableListToString.toString(); } }