Developer:Event Logging and Notifications

From myExperiment
Revision as of 19:27, 5 December 2008 by SergejsAleksejevs (talk | contribs)
(diff) ← Older revision | Latest revision (diff) | Newer revision → (diff)
Jump to: navigation, search

Event Logging, News Generation and Notifications

By Sergejs Aleksejevs, 9th October 2008    /    Last updated on 5th December 2008



Event Logging

acts_as_activity_loggable

myExperiment uses a plugin called acts_as_activity_loggable to deliver event logging functionality. The information about the plugin is available at:

 Note: myExperiment uses a customized version of this plugin, please see below.


Understanding the Plugin Semantics

This plugin makes it extremely easy to deliver event logging functionality. It records 4 main things about every event:

  • action - Rails action name (like "create|update|destroy");
  • culprit - the "subject" of the action, i.e. the entity which performs it;
  • activity_loggable - the "object" of the action, i.e. the entity which is affected by the action;
  • referenced - the entity which is related to the "object" of the action somehow.


The best way to explain this is the example. Consider the event: User X added Item Y to a Pack Z. In this example, "User" is the culprit, "Item" is the activity_loggable and the "Pack" is referenced.


Customized Version of the Plugin

A customized version of the plugin is in use. It is tested to work with Rails 1.2.6 (Ruby 1.8.6) and Rails 2.1.2. It differs from the original one with the following:

  • migration made compatible with Rails 1.2.6 (as well as Rails 2.0);
  • changed the way the actual ActivityLog entry is created (also more compatible with older versions of Rails);
  • "activity_loggable" now always is the current instance of the model, that is "self" in the context of this module;
  • introduced filtering of events to log, so the module will accept an additional parameter (":check_log_allowed => true") indicating that a callback method ("self.log_allowed()") within the model is available, running which would return a boolean result, used to decide if this event is to be logged or not based on the current state of the model.
  • polymorphic associations in the models are now treated better and cleaner when logging the events - for "culprit" and "referenced"
  • if the exception is thrown during logging a particular event, it is caught and added to regular error log ("logger.error") - incomplete entry in ActivityLog table is created in this case
  • plugin will explicitly switch on timestamping for ActiveRecord (by saving the state of timestamping, writing to event log, then restoring the state to the previous value);

also if a timestamp is missing from the model that is being logged it will be set to Time.now, rather than raising exception and failing to log the event - as was in the original plugin


Plugin Installation

[14:23:18] Don Cruickshank says: note for the live update - update environment_private before db:migrate


Plugin Usage

 Note: USE_EVENT_LOG in the examples below is the environment variable that switches logging on / off.

To use the plugin, for each model that requires tracking it's necessary to put some configuration code in it.


  • In the easiest case, the only required line of code is "acts_as_activity_loggable". This will enable logging of every action that takes place with the model, along with a polymorphic pointer to the model instance. culprit and referenced will remain NULL in this case.
 acts_as_activity_loggable


  • To configure the plugin to record culprit and referenced fields, parameter hash needs to be submitted to the plugin. Symbols specified as "models" for culprit and referenced should be associated with the current model (for example, like notions of "user" and "friend" are accocited with Frienship model):
 In Friendship model:
 acts_as_activity_logged :models => { :culprit => { :model => :user },
                                      :referenced => { :model => :friend } } if USE_EVENT_LOG
 In PackRemoteEntry model:
 acts_as_activity_logged :models => { :culprit => { :model => :user },
                                      :referenced => { :model => :pack } } if USE_EVENT_LOG
 In Pack model:
 acts_as_activity_logged :models => { :culprit => { :model => :contributor } } if USE_EVENT_LOG


  • The customized version of the plugin supports event filtering. To switch this feature "on", additional parameter ("check_log_allowed") is to be included into the hash. This will make the plugin to assume that the model implements a callback method called "log_allowed(action_name)". This method accepts action_name of current action and should return a boolean value which would allow (true) or deny (false) logging of current event. This also allows overriding automatic event logging by creating records with custom action names or actors (please see below), but disabling the automatic record - so that the event is still recorded only once.
 In Message model:
 if USE_EVENT_LOG
   acts_as_activity_logged (:models => { :culprit => { :model => :u_from },
                            :referenced => { :model => :u_to } },
                            :check_log_allowed => true
                           )
 end


  • For some models it might be required to record additional actions or events with custom actions and/or actors:
 In log_allowed(action_name) callback in Friendship model:
 ActivityLog.create( :action => "accept", :activity_loggable => self, :culprit => self.friend, :referenced => self.user )


Recorded Events and their Meaning in myExperiment Context

Event logging focuses on CRUD (Create / Read / Update / Destroy) actions with the ability to add custom logging of required events.

On every opportunity all plugin calls to configure event logging are made within the models in the codebase: most of the models are populated with the calls to the plugin, so that basic event logging will be carried out automatically. However, for some models it's required to have more and/or custom events - in cases when it is absolutely necessary (OR when this saves from extra processing) some settings for the plugin may be done in the controllers.

Types of entries in the event log ("activity_logs" table in the DB) are described below:

Message

  • create
  • read - done only by recipient; ":referenced" - sender; recorded when the recipient first opens the message.
  • soft_delete - potentially done by sender & recipient (in these: ":culprit" - the one deleting the message; ":referenced" - the other party); subject marks the message as deleted, but it will remain in the DB until the other party would mark that as deleted too - then the message will be automatically destroyed.
  • destroy - ":culprit" -> sender; ":referenced" -> recipient.
  • [updates are never recorded, because these are meaningless in terms of messages]


Friendship

  • create - done by "user", ":referenced" - "friend".
  • accept - done by "friend", ":referenced" - "user"
  • reject - done by "friend", ":referenced" - "user"; happens when "destroyed" before being accepted.
  • destroy - recorded as done by the party which actually performs the action; happens when "destroyed" after being "accepted".
  • [updates are never recorded, because these are meaningless in terms of friendships]


Membership

[similar to friendships, but fully double-sided relationship - different models (network/user) at two ends, and both can initiate actions]

  • invite - "network" creates membership invite for the "user".
  • request - "user" creates membership request to join the "network".
  • accept - both parties can accept - subject of the action, therefore, should be recorded properly.
  • reject - both parties can "reject" membership; happens when membership was not accepted by both parties before.
  • destroy - both parties can "destroy" membership; happens when the membership was previously accepted by both parties.
 NB! in all actions where the "user" initiates actions (being ":culprit"), the only 
 important fact about the "network" is which network it is - that is the ID of it is
 sufficient. However, when the "network" acts as ":culprit" it is important which
 member of the network has initiated the action. At the moment networks can have only
 one admin, so it's trivial to infer this information, still multiple admins for each
 network could be introduced. To solve this there are two opportunities -
 
 1) "expensive" solution - use "acts_as_extensible" 
 (http://garbageburrito.com/blog/entry/148/rails-plugin-acts-as-extensible) plugin, 
 which allows adding any number of virtual fields to the table, that would be serialized
 into one column called "xml"; then possible to record all the required information -
 drawbacks: space inefficient; large overhead (for most of the events 
 culprit-referenced-activity_loggable triple is more than enough).
 
 2) "cheap" solution - use the same events table to put extra info: for example to make
 a note of which member of the group has initiated the action:
 
 :action - reserved name for "extended" info OR some more useful data
 :activity_loggable - the ActivityLog table entry, which stores main part of info about the event
 :culprit - the desired member
 :referenced - the network


User Profile / Account

  • Profile update done immediately after PictureSelection (in the log) is most likely related to the change of profile picture.
  • "Update" done on the "user" records the fact that the user has updated their account settings.
  • "Update" done on the "user" immediately after the entry for "activate" is meaningless.


Ratings

  • When an item is rated, all older ratings are deleted by "Rating.delete_all()" - so no "destroy" events are logged (this doesn't affect the news feeds, because it checks that the action in the log entry is still valid for displaying in news).
  • This leads to potentially many rating events for the same item in the log - however, this doesn't mean that the older ratings have not been deleted: they've been.


Packs

  • "Update" on a pack means that tags / sharing settings were changed for the pack by its owner; added items won't make the pack "updated".


Things to Watch Out For

The customized plugin will record any thrown exceptions into "logger.error" log. These will look similar to:

 ERROR: acts_as_activity_logged - write_activity_log()
 an incomplete log entry in ActivityLog table was still made - ID = 135
 action: create; activity_loggable: #<Comment:0x8caac30>
 exception caught:
 C:/InstantRails/ruby/lib/ruby/gems/1.8/gems/activesupport-1.4.4/lib/active_support/inflector.rb:247:
   in `constantize': "" is not a valid constant name!
  • The error in the listing above is caused by the code snippet below (and code style which is causing it is very common across the codebase). This is not the problem with the plugin, but is to do with the way instance of the object ("comment" in this example) is created and associated with another model ("blob" in this example). It first creates an object instance, not linked to another model and saves the new record. At this point the plugin is called (":after_save") and the error is produced because the object is not yet associated with the model it should link to.
 comment = Comment.create(:user => current_user, :comment => text)
 @blob.comments << comment

Here's the correct way of doing the same thing (which has better performance as well, because only does one DB access instead of two in the code above):

 Comment.create(:user => current_user, :commentable => @blog, :comment => text)


Still to be done

  • Destroy creditation / attribution when destroying pack / file / workflow(?) - ID of the user initiating the action is not set, as action launched not through the controller.
  • Custom events for "Job" model - submit_and_run!() method has a lot of possible end states, which need to be recorded.


News Generation

Contents of the News Feeds

There are three types of views: the "home" page of a user and the profile pages for users and groups.


1) The user "home" pages show:

  • news for the current user (where current user is explicitly involved in the action as culprit, activity_loggable or referenced);
  • news of friends of the current user (but not for friends of friends or deeper into the recursive tree);
  • network events, where current user is admin or member of (like "Group X was credited for Y" or "Workflow A was shared with Group W");
  • news of members of the groups where the user is admin or member of (but not news of friends of these users or further down recursive tree);
  • site announcements;
  • any actions (added comments, ratings, reviews, citations; uploaded new versions; etc) made to user's owned and user's favourited items - these will be shown no matter who has made these actions: user's friends / fellow members of user's groups / any other users on myExperiement.


2) User's profile page:

  • news for the current user (where current user is explicitly involved in the action as culprit, activity_loggable or referenced);
  • news entries as admin of groups: i.e. news entries, where culprits are the networks, where user is the admin of; this is necessary because things initiated by the group are things done by it's admin - and for now there is only one admin per group.


3) Group's profile page:

  • news for the current group (where current group is explicitly involved in the action as culprit, activity_loggable or referenced);
  • (these will include members joining and leaving; items shared with the group; credit given to the group; tags associated with the group; etc)


Viewing Permissions for the News

Before being displayed to the user, every entry in the news feed passes through validation and authentication process: checks that relevant objects are still presents in the database and still hold the desired state are made first; then authentication check is made to see if the current viewer of the news feed is authorized to "view" every object involved in the news entry. See details about the authentication below.

 (all events will be also visible to the "culprit" of the action - because authorization
 will have happened to allow that user to perform a certain action, so safe to allow them
 to view the news items, too)


  • Workflows
    • no events are shown in the news, everything is inferred from activity log entries on Workflow Versions


  • Workflow versions
    • "create" and version == 1 --> shown as "new workflow created"
    • "create" and version > 1 --> shown as "new workflow version added for X workflow"
    • "update" -> shown as "edited version X of workflow Y"
    • Note: all these news entries are only available to those who are authorized to view the workflow


  • Files, Packs
    • "create" / "update" --> news item visible to anyone, who is allowed to view the contributable


  • Pack Items (on their creation - that is when "added" to the pack)
    • Contributable items --> all those that can view the pack & the item, can view the news item about these
    • External items --> news item visible to all those, who can view the pack


  • Memberships
    • "accept" / "destroy" --> anyone can see users joining / leaving the groups
    • "invite" / "request" / "reject" --> news items visible only to the "user" and the "group admin"


  • Friendships
    • "accept" / "destroy" --> anyone can see users becoming / stopping being friends
    • "create" / "reject" --> news items visible only to the "user" and the "group admin"


  • Groups
    • "create" --> anyone can see new groups being created


  • GroupAnnouncement
    • "create" --> public announcements visible to anyone; private should only be shown to group members


  • Permissions
    • "create" / "update" --> those affected by the permissions should see the news item (because these are given to users / groups to allow access to affected contributables)
    • (NB! other users might be able to view the contributables shared with the group by this permission, but they will not get that piece of news displayed - even though they would be able see the item in shared items)


  • Ratings, Bookmarks (Favourites), Comments, Reviews, Creditations, Taggings, Citations
    • "create" --> news item only visible to those, who have permissions to view affected contributables
    • "update" --> _only for Ratings_; treated the same as all "create"s


  • Attributions
    • "create" --> visible to those who are allowed to view both what and to what something is attributed


  • Profile picture updates
    • "create" --> anyone can view


  • Profiles
    • "update" --> all user's friends can see news about this
    • (reflects changes like contact details / occupation / location / interests / etc about a user)


  • Users
    • "activate" --> anyone allowed to see how a user joins (effectively this is the right moment, not when the user has first registered, but hasn't confirmed their email address yet)
    • "update" --> not shown to anyone (reflects updates like display name, notification settings, etc)


Event Grouping

Similar events often happen in a row - for example, many different objects are created when someone uploads a workflow: tags, creditations, attributions. There is a clear need to group such events together, which would result in more succint news entries - so we get something resembling "UserX tagged workflowY with 'my', 'new', 'workflow'" instead of having 3 different news entries (one per separate tag).

Current Implementation

This feature has 3 independent stages, which are followed in sequence:

  1. choosing pairs of events that can potentially be grouped together;
  2. making decision whether the chosen pair of events should be grouped;
  3. having some compound events, we need to display them.

The first step is now implemented to minimize computational efforts when producing grouping. Log entries are sorted in reverse-chronological order for news presentation afterwards, and the grouping mechanism utilizes the element order: one pass through the collection of log entries makes it only possible to collapse consecutive events of similar type into one:

 * starting with some element we call it the "base event" - the "start of the sequence"
 * check if the next element is not too far in time from the base event and if it has the same type (i.e. can be grouped with the base event)
 ** if it is, current event is removed and the base event receives some extra information from the deleted event
 ** if it's not, old sequence is finalized, and the current element becomes the start of new sequence
 * continue with the next element as described above


 NB! This algorithm can potentiall be improved (with little performance losses) by splitting
 ALL events into partitions based on their timestamp - so events that happened close to each
 other will reside in the same partition. Analyze all events in the partition to perform 
 grouping - this will allow for events grouped with each other even if they are not in the
 consecutive records in the DB.

Currently Grouped Events

  • Creditations
  • Attributions
  • Bookmarks
  • Taggings
  • Profile updates


Caching

Timed caching is used for all the news feeds. By default this time is set to 5 minutes, however is easily configurable through "environment_private.rb" config file.

Home Page
  • "My News" are visible only by logged in users to themselves - therefore, one "view" over this page exists and is being cached.
  • "Public News" - visible to all and are a shared view for all users.
User / Group Profile Page

Many different users (including anonymous) can view these pages. Access rights affecting various items in the news feeds for these users may be different - this means that each profile page is cached per viewer (and all anonymous viewers will share one cache fragment).