Use MarkusLogger in our code. See review 303. Closes ticket MarkUsPro…

…ject#539.

app/controllers/assignments_controller.rb

@@ -170,6 +170,8 @@ def join_group
     @grouping = Grouping.find(params[:grouping_id])
     @user = Student.find(session[:uid])
     @user.join(@grouping.id)
+    m_logger = MarkusLogger.instance
+    m_logger.log(I18n.t("markus_logger.student_accepted_invitation", :user_name => @user.user_name, :group => @grouping.group.group_name))
     redirect_to :action => 'student_interface', :id => params[:id]
   end
 
@@ -178,12 +180,15 @@ def decline_invitation
     @grouping = Grouping.find(params[:grouping_id])
     @user = Student.find(session[:uid])
     @grouping.decline_invitation(@user)
+    m_logger = MarkusLogger.instance
+    m_logger.log(I18n.t("markus_logger.student_declined_invitation", :user_name => @user.user_name, :group => @grouping.group.group_name))
     redirect_to :action => 'student_interface', :id => params[:id]
   end
 
   def creategroup
     @assignment = Assignment.find(params[:id])
     @student = @current_user
+    m_logger = MarkusLogger.instance
 
     begin
       # We do not allow group creations by students after the due date
@@ -201,15 +206,18 @@ def creategroup
           raise "You cannot work alone for this assignment - the group size minimum is #{@assignment.group_min}"
       end
       @student.create_autogenerated_name_group(@assignment.id)
+      m_logger.log(I18n.t("markus_logger.student_created_group", :user_name => @student.user_name), MarkusLogger::INFO)
     rescue RuntimeError => e
       flash[:fail_notice] = e.message
+      m_logger.log(I18n.t("markus_logger.student_create_group_fail", :user_name => @student.user_name, :error => e.message), MarkusLogger::ERROR)
     end
     redirect_to :action => 'student_interface', :id => @assignment.id
   end
 
   def deletegroup
     @assignment = Assignment.find(params[:id])
     @grouping = @current_user.accepted_grouping_for(@assignment.id)
+    m_logger = MarkusLogger.instance
     begin
       if @grouping.nil?
         raise "You do not currently have a group"
@@ -228,9 +236,11 @@ def deletegroup
       @grouping.update_repository_permissions
       @grouping.destroy
       flash[:edit_notice] = "Group has been deleted"
+      m_logger.log(I18n.t("markus_logger.student_deleted_group", :user_name => current_user.user_name, :group => @grouping.group.group_name), MarkusLogger::INFO)
 
     rescue RuntimeError => e
       flash[:fail_notice] = e.message
+      m_logger.log(I18n.t("markus_logger.student_delete_group_fail", :user_name => current_user.user_name, :group => @grouping.group.group_name, :error => e.message), MarkusLogger::ERROR)
     end
     redirect_to :action => 'student_interface', :id => params[:id]
   end
@@ -250,6 +260,7 @@ def invite_member
     to_invite = params[:invite_member].split(',')
     flash[:fail_notice] = []
     flash[:success] = []
+    m_logger = MarkusLogger.instance
     to_invite.each do |user_name|
       user_name = user_name.strip
       @invited = Student.find_by_user_name(user_name)
@@ -280,8 +291,12 @@ def invite_member
 
         @invited.invite(@grouping.id)
         flash[:success].push(I18n.t('invite_student.success', :user_name => @invited.user_name))
+        m_logger.log(I18n.t("markus_logger.student_invited_student", :inviter => @student.user_name, :invitee => @invited.user_name))
       rescue Exception => e
         flash[:fail_notice].push(e.message)
+        m_logger.log(I18n.t('markus_logger.student_invitation_failure',
+                            { :inviter => @student.user_name, :invitee => @invited.user_name,
+                              :error => e.message }), MarkusLogger::ERROR)
       end
     end
     redirect_to :action => 'student_interface', :id => @assignment.id
@@ -292,11 +307,14 @@ def invite_member
   def disinvite_member
     @assignment = Assignment.find(params[:id])
     membership = StudentMembership.find(params[:membership])
+    disinvited_student = membership.user
     membership.delete
     membership.save
     # update repository permissions
     grouping = current_user.accepted_grouping_for(@assignment.id)
     grouping.update_repository_permissions
+    m_logger = MarkusLogger.instance
+    m_logger.log(I18n.t('markus_logger.student_cancelled_invitation', :inviter => current_user.user_name, :invitee => disinvited_student.user_name))
     flash[:edit_notice] = "Member disinvited" 
   end
 

app/controllers/main_controller.rb

@@ -85,6 +85,8 @@ def logout
     clear_session
     cookies.delete :auth_token
     reset_session
+    m_logger = MarkusLogger.instance
+    m_logger.log(I18n.t("markus_logger.user_logout_message", :user_name => current_user.user_name))
     redirect_to :action => 'login'
   end
 

app/controllers/results_controller.rb

@@ -10,9 +10,6 @@ class ResultsController < ApplicationController
   before_filter      :authorize_for_user, :only => [:codeviewer]
   before_filter      :authorize_for_student, :only => [:view_marks]
 
-  def index
-  end
-
   def note_message
     @result = Result.find(params[:id])
     if params[:success]
@@ -81,6 +78,9 @@ def edit
         @previous_grouping = groupings[current_grouping_index - 1]
       end
     end
+    m_logger = MarkusLogger.instance
+    m_logger.log(I18n.t("markus_logger.user_viewed_submission", :user_name => current_user.user_name, :group_name => @group.group_name, :submission_id => @submission.id, :assignment => @assignment.short_identifier))
+
   end
 
   def next_grouping
@@ -98,6 +98,17 @@ def set_released_to_students
     @result.released_to_students = released_to_students
     @result.save
     @result.submission.assignment.set_results_average
+    m_logger = MarkusLogger.instance
+    assignment = @result.submission.assignment
+    if params[:value] == 'true'
+      m_logger.log(I18n.t("markus_logger.marks_released_for_assignment",
+                            :assignment_id => assignment.id,
+                            :assignment => assignment.short_identifier, :number_groups => 1))
+    else
+      m_logger.log(I18n.t("markus_logger.marks_unreleased_for_assignment",
+                            :assignment_id => assignment.id,
+                            :assignment => assignment.short_identifier, :number_groups => 1))
+    end
   end
 
   #Updates the marking state
@@ -155,9 +166,21 @@ def update_mark
     result_mark = Mark.find(params[:mark_id])
     mark_value = params[:mark]
     result_mark.mark = mark_value
+    submission = result_mark.result.submission  # get submission for logging
+    group = submission.grouping.group           # get group for logging
+    assignment = submission.grouping.assignment # get assignment for logging
+    m_logger = MarkusLogger.instance
     if !result_mark.save
+      m_logger.log(I18n.t('markus_logger.user_update_mark_submission_fail',
+                    { :user_name => current_user.user_name, 
+                      :submission_id => submission.id, :group_name => group.group_name,
+                      :assignment => assignment.short_identifier}), MarkusLogger::INFO)
       render :partial => 'shared/handle_error', :locals => {:error => I18n.t('mark.error.save') + result_mark.errors}
     else
+      m_logger.log(I18n.t('markus_logger.user_update_mark_submission',
+                    { :user_name => current_user.user_name, 
+                      :submission_id => submission.id, :group_name => group.group_name,
+                      :assignment => assignment.short_identifier}), MarkusLogger::ERROR)
       render :partial => 'results/marker/update_mark',
              :locals => { :result_mark => result_mark, :mark_value => mark_value}
     end
@@ -198,6 +221,9 @@ def view_marks
       mark.save(false)
       @marks_map[criterion.id] = mark
     end
+    m_logger = MarkusLogger.instance
+    m_logger.log(I18n.t('markus_logger.student_viewed_result', :user_name => current_user.user_name,
+                                                      :assignment => @assignment.short_identifier))
   end
 
   def add_extra_mark

app/controllers/submissions_controller.rb

@@ -258,18 +258,21 @@ def update_files
     # Create transaction, setting the author.  Timestamp is implicit.
     txn = repo.get_transaction(current_user.user_name)
 
+    log_messages = []
     begin
       # delete files marked for deletion
       delete_files.keys.each do |filename|
         txn.remove(File.join(assignment_folder, filename), file_revisions[filename])
+        log_messages.push(I18n.t("markus_logger.student_deleted_file", :user_name => current_user.user_name, :file_name => filename, :assignment => assignment.short_identifier))
       end
 
       # Replace files
       replace_files.each do |filename, file_object|
-	# Sometimes the file pointer of file_object is at the end of the file.
-	# In order to avoid empty uploaded files, rewind it to be save.
-	file_object.rewind
+        # Sometimes the file pointer of file_object is at the end of the file.
+        # In order to avoid empty uploaded files, rewind it to be save.
+        file_object.rewind
         txn.replace(File.join(assignment_folder, filename), file_object.read, file_object.content_type, file_revisions[filename])
+        log_messages.push(I18n.t("markus_logger.student_replaced_file", :user_name => current_user.user_name, :file_name => filename, :assignment => assignment.short_identifier))
       end
 
       # Add new files
@@ -278,10 +281,11 @@ def update_files
         if file_object.original_filename.nil?
           raise "Invalid file name on submitted file"
         end
-	# Sometimes the file pointer of file_object is at the end of the file.
-	# In order to avoid empty uploaded files, rewind it to be save.
-	file_object.rewind
+        # Sometimes the file pointer of file_object is at the end of the file.
+        # In order to avoid empty uploaded files, rewind it to be save.
+        file_object.rewind
         txn.add(File.join(assignment_folder, sanitize_file_name(file_object.original_filename)), file_object.read, file_object.content_type)
+        log_messages.push(I18n.t("markus_logger.student_submitted_file", :user_name => current_user.user_name, :file_name => file_object.original_filename, :assignment => assignment.short_identifier))
       end
 
       # finish transaction
@@ -294,6 +298,11 @@ def update_files
         flash[:update_conflicts] = txn.conflicts
       else
         flash[:success] = I18n.t('update_files.success')
+        # flush log messages
+        m_logger = MarkusLogger.instance
+        log_messages.each do |msg|
+          m_logger.log(msg)
+        end
       end
 
       # Are we past collection time?    
@@ -361,11 +370,20 @@ def update_submissions
         groupings = assignment.groupings.find(params[:groupings])
       end
     end
-
+
+    log_message = ""       
     if !params[:release_results].nil?
       changed = set_release_on_results(groupings, true, errors)
+      log_message = I18n.t("markus_logger.marks_released_for_assignment",
+                            :assignment_id => assignment.id,
+                            :assignment => assignment.short_identifier,
+                            :number_groups => changed)
     elsif !params[:unrelease_results].nil?
       changed = set_release_on_results(groupings, false, errors)
+      log_message = I18n.t("markus_logger.marks_unreleased_for_assignment",
+                            :assignment_id => assignment.id,
+                            :assignment => assignment.short_identifier,
+                            :number_groups => changed)
     end
 
 
@@ -375,6 +393,8 @@ def update_submissions
 
     if changed > 0
       flash[:success] = I18n.t('results.successfully_changed', {:changed => changed})
+      m_logger = MarkusLogger.instance
+      m_logger.log(log_message)
     end
     flash[:errors] = errors
 
@@ -389,6 +409,12 @@ def unrelease
       params[:groupings].each do |g|
         g.unrelease_results
       end
+      m_logger = MarkusLogger.instance
+      assignment = Assignment.find(params[:id])
+      m_logger.log(I18n.t("markus_logger.marks_unreleased_for_assignment",
+                  :assignment_id => assignment.id,
+                  :assignment => assignment.short_identifier,
+                  :number_groups => params[:groupings].length))
     end
     redirect_to :action => 'browse', :id => params[:id]
   end

app/models/markus_logger.rb

@@ -9,7 +9,6 @@
 
 class MarkusLogger
 
-
   # This class must use the singleton pattern since
   # we only want one instance of this class through the whole
   # program.
@@ -43,9 +42,10 @@ class MarkusLogger
   # The variables that the loggers will use are defined in the
   # environment.rb file
   #===Exceptions
-  # If the configuration variables MARKUS_LOGGING_ROTATE_INTERVAL, MARKUS_LOGGING_ERRORLOGFILE, MARKUS_LOGGING_LOGFILE
-  # or MARKUS_LOGGING_SIZE_THRESHOLD are not valid an exception of type MarkusLoggerConfigurationError
-  # is raised
+  # If the configuration variables MARKUS_LOGGING_ROTATE_INTERVAL,
+  # MARKUS_LOGGING_ERRORLOGFILE, MARKUS_LOGGING_LOGFILE
+  # or MARKUS_LOGGING_SIZE_THRESHOLD are not valid an exception of type
+  # MarkusLoggerConfigurationError is raised.
   def initialize
     rotate_by_time = markus_config_logging_rotate_by_interval
     size = markus_config_logging_size_threshold
@@ -62,32 +62,36 @@ def initialize
       end
       @__logger__ = Logger.new(log_file, interval)
       @__logger__.formatter = Logger::Formatter.new
+      @__logger__.datetime_format = "%Y-%m-%d %H:%M:%S  "
       @__errorLogger__ = Logger.new(error_log_file, interval)
       @__errorLogger__.formatter = Logger::Formatter.new
+      @__errorLogger__.datetime_format = "%Y-%m-%d %H:%M:%S  "
     else
       if size > 0
         if old_files <= 0
           raise MarkusLoggerConfigurationError.new('The number of old logfiles to keep has to be bigger than 0')
         end
         @__logger__ = Logger.new(log_file, old_files, size)
         @__logger__.formatter = Logger::Formatter.new
+        @__logger__.datetime_format = "%Y-%m-%d %H:%M:%S  "
         @__errorLogger__ = Logger.new(error_log_file, old_files, size)
         @__errorLogger__.formatter = Logger::Formatter.new
+        @__errorLogger__.datetime_format = "%Y-%m-%d %H:%M:%S  "
       else
         raise MarkusLoggerConfigurationError.new('The threshold size for the logger has to be bigger than 0')
       end
     end
   end
 
 
-#=== Description
-#Logs a message with the given log level severity. The default log level value is INFO.
-#Any message that can be turned to a string will be logged, else the output of the inspect
-#method will be logged.
-#=== Return
-#true if successful, false otherwise.
-#=== Exceptions
-#When the log level is not known then an exception of type ArgumentError is raised
+  #=== Description
+  # Logs a message with the given log level severity. The default log level value is INFO.
+  # Any message that can be turned to a string will be logged, else the output of the inspect
+  # method will be logged.
+  #=== Return
+  # true if successful, false otherwise.
+  #=== Exceptions
+  # When the log level is not known then an exception of type ArgumentError is raised
   def log(msg, level=INFO)
     case level
     when INFO
@@ -105,11 +109,11 @@ def log(msg, level=INFO)
     end
   end
 
-#=== Description
-#Checks if the filename is valid
-#=== Return
-#true if the file exists and it is writable or if the file doesn't exist and  the
-#directory of the file is writable and it exists, false otherwise.
+  #=== Description
+  # Checks if the filename is valid
+  #=== Return
+  # true if the file exists and it is writable or if the file doesn't exist and  the
+  # directory of the file is writable and it exists, false otherwise.
   def valid_file?(f)
     dir = File.dirname(f)
     if(File.file?(f) && File.writable?(f))
@@ -127,5 +131,4 @@ def valid_file?(f)
 
 # Exception type called by MarkusLogger
 class MarkusLoggerConfigurationError < Exception
-
 end

app/models/user.rb

@@ -62,22 +62,23 @@ def self.authenticate(login, password)
       pipe = IO.popen(VALIDATE_FILE, "w+")
       pipe.puts("#{login}\n#{password}") # write to stdin of markus_config_validate
       pipe.close
-      @logger = MarkusLogger.instance
+      m_logger = MarkusLogger.instance
       case $?.exitstatus
         when 0
-          @logger.log("User #{login} logged in",MarkusLogger::INFO)
+          m_logger.log(I18n.t("markus_logger.user_login_message", :user_name => login), MarkusLogger::INFO)
           return AUTHENTICATE_SUCCESS
         when 1
-          @logger.log("Wrong username/password: #{login}",MarkusLogger::ERROR)
+          m_logger.log(I18n.t("markus_logger.user_wrong_credentials", :user_name => login), MarkusLogger::ERROR)
           return AUTHENTICATE_NO_SUCH_USER
         when 2
-          @logger.log("Wrong username/password: #{login}",MarkusLogger::ERROR)
+          m_logger.log(I18n.t("markus_logger.user_wrong_credentials", :user_name => login), MarkusLogger::ERROR)
           return AUTHENTICATE_BAD_PASSWORD
         else
-          @logger.log("Error while logging in user: #{login}",MarkusLogger::ERROR)
+          m_logger.log(I18n.t("markus_logger.user_login_error", :user_name => login),MarkusLogger::ERROR)
           return AUTHENTICATE_ERROR
       end
     else
+      m_logger.log(I18n.t("markus_logger.user_login_error", :user_name => login),MarkusLogger::ERROR)
       return AUTHENTICATE_BAD_CHAR
     end
   end

app/views/results/marker/_expand_unmarked_criteria.rjs

@@ -1,4 +1,4 @@
 nil_marks.each do |nil_mark|
-  page.call "show_rubric_criterion", nil_mark.rubric_criterion.id
+  page.call "show_rubric_criterion", nil_mark.markable.id
 end