CSC/ECE 517 Fall 2016 E1703: Logging for Expertiza

Introduction

Currently, Expertiza doesn’t log anything, beyond the events in the console log. But often we need to know when a student logged in, reserved a topic, dropped off a team, etc. This will help the admin/instructor verify claims made by the student saying that he had submitted something or did some other activity that but didnt get reflected in expertiza due to a bug, a network issue or something else that went wrong. In a production environment, logs are the best way to debug the application when something goes wrong. In the absence of logs, it is very difficult for a developer/support technician to debug and analyze what went wrong.

In a production environment, logs are the best way to debug the application when something goes wrong. In the absence of logs, it is very difficult for a developer/support technician to debug and analyze what went wrong.

Events to Log

Student Activity

Logins, logouts, signups, submission of files/links (although there is already a log of when links are submitted), issuing invitations, joining teams, dropping off teams, requesting reviews, submitting reviews (or author feedback, or teammate reviews, or meta-reviews), undoing any of these operations.

Instructor/TA/Admin Activity

Creating/editing courses and assignments, giving grades, impersonating other users, adding TAs, adding participants to courses or assignments, assigning reviewers.

What we plan to implement

There are two parts to this project:

• Logging the events and other information that will help in debugging
• Creating a GUI to interpret the logs and show events for a particular user in a particular time frame.

We are planning to use the logging framework that comes inbuilt with rails. Rails makes use of the ActiveSupport::Logger class to write log information. Each log statement in the program has a level associated with it which indicates their importance.

The hierarchy of log messages is as below:

• UNKNOWN : An unknown message that should always be logged.
• FATAL  : A unhandleable error that results in a program crash
• ERROR  : A handleable error condition
• WARN  : Warnings
• INFO  : Useful info about system operation
• DEBUG  : Low level info for developers to help with debugging.

In the config file, we can specify the level of logs to be printed. A log statement in the program will be printed only if its level is equal to or higher than the level set in the config file.

Usually in production, we set the level to INFO or WARN and in in a development environment, we set it to debug which will print out all the finer details of the state of the system which helps in debugging.

Currently, the expertiza code contains very little logging statement and it does not record student/instructor or TA activity. The current logs are also of little or no help to a developer/ support technician trying to debug the code when something goes wrong.

We plan on improving the current log statements by adding more information to it so that it becomes more useful to the person trying to debug the code and will also record all student, TA and instructor activities. We will also be adding more log statements which will make it easier to track all student, TA and instructor activities.

For the second part of the project, we will create a view that is accessible only to the admin from his console. This view will list out the events by interpreting the logs and give an option to filter it based on user and date.

Design

Logging

We are planning to standardize the log statements by giving them a predefined format. This will also help us in the second part of the project which is to interpret the logs and display student activities in a GUI. This is the format we propose:

• INFO:

[TimeStamp: |&controller_name|method|roleid|userid|event: {login|submission|.....}|event_description]
We will use this to log entry into methods and to log events like login, submission, joining teams, leaving teams, creating assignments, inviting other user to team etc.

In the production environment, we will limit the logs to INFO mode, i.e it will print out only the errors and events.

In development environment, we will set the logger mode to DEBUG. This will print out all the logs including errors, events and debug statements. This will help the developer in debugging the code when something goes wrong.

Interpreting the Logs

This is the second part of the project. We will be creating a GUI to interpret and make sense of all the log data. The GUI will display the events for each user. We will also give an option to filter the event listing based on date and events.

This is a rough sketch of what the page will look like:



It will have a text field to specify the user ID, a drop down menu to select the event and two date picker fields to specify the begin and end dates for the logs

Implementation

Changes in existing files

We have also inserted new code in the following controllers:

• application_controller.rb
• admin_controller.rb
• advice_controller.rb
• assignment_questionnaire_controller.rb
• assignment_signups_controller.rb
• assignments_controller.rb
• auth_controller.rb
• course_controller.rb
• impersonate_controller.rb
• import_file_controller.rb
• invitation_controller.rb
• questionnaires_controller.rb
• response_controller.rb
• review_mapping_controller.rb
• submitted_content_controller.rb
• teams_controller.rb

Defined a logger object in the application_controller that points to our new log file: events.log. Since this is defined in the application controller, it will be accessible in all the controllers and there is no need to redefine it again in the other controllers where we use it to log events. We have added a total of 45 logging statements for different events.

The new code in the other controllers are simple logging statements to log events, does not affect the functionality of the existing code in any way.

New Controllers

• logger_controller.rb

We created a new controller for reading and filtering the log records. This has two actions, for viewing the logs and for filtering the logs based on input from the user.

New Models

• log_entry.rb

This model was created to represent each log statement in the record. It contains fields that pertain to a log entry like the time, userid, event and log description

New Views

• view_logs.html.erb

This is the view we created for viewing the logs records. The used is also given an option to filter the logs based on time, userid, user type and event type.

Each log entry has a serial number, timestamp, name of the event, description of the event, type of the user involved in the event and userID of the user. We have provided the option to search the logs by user type, userID, event type and time. You can notice that there is a second search field below just above the table. It does an in page search of the results that are currently loaded. Its faster if you dont want the latest logs. It will search only the records that were present in the log file when the page was loaded. If you want to search the latest logs, i.e logs that have been added after the page was loaded, you need to use the first search button. This search will be comparatively slower as it involves a controller hit and redirection back to the view page.

Testing

RSpec Testing

We have written a feature test in RSpec for the logger module. We have created a new class: logger_spec.rb for the test cases.

Test 1

If the user having less privileges than an admin tries to access the log viewer page, then he/she gets a authentication failure message.

Future Extension

This project can be easily extended by adding more log statements to additional or new events by simply making a log entry with our logger object in the specified format. If proper format is followed, it will get picked up by the parser and will be visible in the view.

Conclusion

We learned a lot doing this project. It was a good experience contributing to open source software. We got a chance to add an entire model, view and controller to the existing codebase. We also had to read through all the existing controller code to insert logging statements at proper locations to log user activity. This was a good learning experience.