source: main/waeup.kofa/trunk/docs/source/userdocs/datacenter/logging.rst @ 12893

.. _logging:

Logfiles
********

Kofa is logging actions, which cause changes to the database or the filesystem, in separate human-redable event logfiles. Nearly all actions are being logged, except those committed by applicants and students during registration periods. During these data initialization periods, applicants and students are requested to edit many fields and upload heaps of scanned documents. Logging all these changes would mean filling the logfiles with more or less useless or redundant information. The main purpose of Kofa's logging facilities is to trace changes effected by portal officers. Applicants and students can only access their own data. They don't have the permission to change anything else. Whereas portal officers bear responsibility for the integrity of the whole database. Depending on the roles they have, officers can add, edit or remove application and study data without leaving a trace in the object database itself. Kofa closes this security gap by recording nearly all actions of portal officers into various event logfiles.

.. note::

 Kofa logs the changing but not the viewing of data (except downloading export files or reports). Also entering (login) end leaving (logout) the portal is **not** being recorded.

Critics may claim that extensive logging may discourage officers from working with the portal. Persons in key functions often don't want to be controlled or supervised by anybody else. Indeed, Kofa does not respond to the desire for this kind of privacy. Datacenter managers can search all logfiles and can even see what their principles have done with the data. Goal behind is **transparency and security**, i.e. transparent data processing and reduction of the vulnerability to corruption combined with cutting-edge technologies to protect the data against attacks from outside.

Logfiles can not be accessed directly. They can neither be downloaded nor viewed entirely online. But the files can be searched online for arbitrary `regular expressions`_. The simplest regular expression is a single word or a string. A technical description, how logfiles are being querried, can be found :py:meth:`here<waeup.kofa.datacenter.DataCenter.queryLogfiles>`.

Each line in the logfile means a single log entry. It is composed of four parts: a datetime string, the log level (mainly 'INFO'), the id of the logged-in user, and a message part. Depending on the module, the message part is subdivided into further parts which are described below.


main.log
========

All actions in the academic section are logged in ``main.log``. Changes of faculties, departments, certificates, courses and certificate courses done via pages in the user interface (browser page) are recorded in the following form::

  2014-12-11 13:09:22,855 - INFO - admin - browser.pages.DepartmentAddFormPage - added: FAC1/DEP1
  2014-12-11 13:19:31,755 - INFO - admin - browser.pages.DepartmentManageFormPage - DEP1 - saved: title
  2014-12-12 13:19:43,255 - INFO - admin - browser.pages.FacultyManageFormPage - removed: DEP1

The message part is composed of the browser page name and the action taken. In the example above a department ``DEP1`` was added on December 11, 2014 by user ``admin`` in faculty ``FAC1``, the title was changed 10 minutes later and, finally, the department was entirely removed one day later. In the same way user data and configuration data are logged in the main logfile. Examples::


  2015-04-01 08:33:47,474 - INFO - admin - browser.pages.UserManageFormPage - Test edited: roles
  2015-04-27 09:39:24,073 - INFO - admin - browser.pages.SessionConfigurationAddFormPage - added: 2014

Furthermore, ``main.log`` does contain information about reports::

  2015-04-28 15:34:31,852 - INFO - admin - students.reports.student_statistics.StudentStatisticsReportGeneratorPage - report 3029 created: Student Statistics (session=1989, mode=All, breakdown=faccode)
  2015-04-28 15:34:37,698 - INFO - admin - students.reports.student_statistics.StudentStatisticsReportPDFView - report 3029 downloaded: StudentStatisticsReport_1989_1990_All_2015-04-28_13-34-36_UTC.pdf
  2015-04-28 15:36:30,106 - INFO - admin - browser.reports.ReportsContainerPage - report 3029 discarded

the management of documents::

  2015-01-09 17:30:49,819 - INFO - admin - HOWTO - Document created
  2015-01-09 17:30:49,822 - INFO - admin - documents.browser.DocumentAddFormPage - added: REST Document HOWTO

password change requests and the usage of password mandates::

  2015-04-28 13:42:52,753 - INFO - zope.anybody - browser.pages.ChangePasswordRequestPage - B1234567 - myname@gmail.com
  2015-04-28 13:43:51,056 - INFO - zope.anybody - PasswordMandate used: B1234567

``zope.anybody`` is the user id of anonnymous (non-logged-in) users.

Some log entries do not contain information about a browser page. These entries were generated deeper in the system. The ``Document created`` entry, for example, was added by a workflow transition. The ``PasswordMandate used`` entry was added by :py:meth:`waeup.kofa.mandates.mandate.PasswordMandate.execute` and not directly by the browser page which calls this method (:py:meth:`waeup.kofa.mandates.browser.MandateView.update`).

``main.log`` is also the place where plugins store information about system upgrades. If catalogs have to be re-indexed or new attributes of objects have to
be initialized, a corresponding message is stored in the main logfile.


datacenter.log
==============

All actions in the data center are logged in ``datacenter.log``. These are uploading import files, processing import files and downloading any kind of datacenter file::

  2015-04-29 06:52:23,483 - INFO - admin - browser.pages.DatacenterUploadPage - uploaded: /kofa/trunk/var/datacenter/users_admin.csv
  2015-04-29 06:52:44,025 - INFO - admin - processed: /kofa/trunk/var/datacenter/users_admin.csv, update mode, 3 lines (0 successful/ 3 failed), 0.129 s (0.0430 s/item)
  2015-04-29 06:53:10,404 - INFO - admin - browser.pages.DatacenterPage - deleted: users_admin.update.pending.csv
  2015-04-29 06:54:41,963 - INFO - admin - browser.pages.DatacenterUploadPage - uploaded: /kofa/trunk/var/datacenter/users2_admin.csv
  2015-04-29 06:54:51,748 - INFO - admin - processed: /kofa/trunk/var/datacenter/users2_admin.csv, create mode, 3 lines (3 successful/ 0 failed), 0.024 s (0.0079 s/item)

In the example above a user data file ``users.csv`` was uploaded and processed in update mode. The import failed since the 3 users didn't exist. The file was then deleted. User ``admin`` uploaded the file a second time. The file name had to be changed because the uploader does not allow to upload files with same name twice. The file was finally successfully processed in create mode.

Also the export of data (export, download and discard) is recorded in detail::

  2015-04-29 06:55:20,485 - INFO - admin - browser.pages.ExportCSVPage - exported: certificates, job_id=3036
  2015-04-29 06:55:25,697 - INFO - admin - browser.pages.ExportCSVView - downloaded: WAeUP.Kofa_certificates_3036.csv, job_id=3036
  2015-04-29 06:55:30,579 - INFO - admin - browser.pages.ExportCSVPage - discarded: job_id=3036


accesscodes.log
===============

The creation of access code batches, disabling and re-enabling of single access codes and archiving and removal of entire batches is logged as follows::

  2015-04-29 08:12:26,091 - INFO - admin - accesscodes.browser.AddBatchPage - created: ABC-1-2015_04_29_06_12_24-admin.csv (1000, 2300.000000)
  2015-04-29 08:13:07,024 - INFO - admin - accesscodes.browser.BatchContainerSearchPage - disabled: ABC-1-6003657048
  2015-04-29 08:13:11,502 - INFO - admin - accesscodes.browser.BatchContainerSearchPage - (re-)enabled: ABC-1-6003657048
  2015-04-29 08:14:13,668 - INFO - admin - accesscodes.browser.BatchContainerPage - archived: ABC-1 (ABC-1_archive-2015_04_29_06_14_13-admin.csv)
  2015-04-29 08:14:14,152 - INFO - admin - accesscodes.browser.BatchContainerPage - deleted: ABC-1

Not all access code workflow transitions are being logged. Each access code has a history attribute which contains a detailed list of all transitions. The history is shown on the `BatchContainerSearchPage`.


applicants.log
==============

The creation, editing and removal of applicants containers as well as editing application records (applicants) is being logged. Also the approval of payment tickets and all other payment ticket transactions are being recorded in ``applicants.log``. Kofa also logs all workflow transitions into both the applicant's history attribute and the logfile. Okay, this is somehow redundant, but it has proved useful to get a complete overview over all application data transactions also in the logfile. In return, Kofa does not aditionally log actions of browser pages if a workflow transition is triggered at the same time. Let's see the example::

  2015-04-29 10:14:40,565 - INFO - admin - applicants.browser.ApplicantsContainerAddFormPage - added: app2015
  2015-04-29 10:14:45,398 - INFO - admin - applicants.browser.ApplicantsContainerManageFormPage - app2015 - saved: startdate + enddate + application_fee
  2015-04-29 10:15:08,779 - INFO - admin - app2015_262037 - Application initialized
  2015-04-29 10:15:28,703 - INFO - admin - app2015_262037 - Application started
  2015-04-29 10:15:28,704 - INFO - admin - applicants.browser.ApplicantManageFormPage - app2015_262037 - saved: reg_number + sex + course1 + date_of_birth
  2015-04-29 10:16:27,654 - INFO - admin - applicants.browser.ApplicationFeePaymentAddPage - app2015_262037 - added: p4302953958139
  2015-04-29 10:16:38,921 - INFO - admin - app2015_262037 - Payment approved
  2015-04-29 10:16:38,922 - INFO - admin - applicants.browser.OnlinePaymentApprovePage - app2015_262037 - approved: p4302953958139
  2015-04-29 10:16:58,026 - INFO - admin - app2015_262037 - Application submitted
  2015-04-29 10:17:01,040 - INFO - admin - applicants.browser.ApplicantManageFormPage - app2015_262037 - saved: course_admitted
  2015-04-29 10:17:10,978 - INFO - admin - app2015_262037 - Applicant admitted
  2015-04-29 10:17:10,979 - INFO - admin - applicants.browser.ApplicantManageFormPage - app2015_262037 - saved: locked
  2015-04-29 10:17:34,135 - INFO - admin - app2015_262037 - Student record created (K1000004)
  2015-04-29 10:45:15,298 - INFO - admin - app2015_262037 - Applicant record removed
  2015-04-29 10:45:15,299 - INFO - admin - applicants.browser.ApplicantsRootManageFormPage - removed: app2015

An applicants container was added first. The `startdate`,  `enddate` and the `application_fee` attributes were edited and a new application record (applicant) was added some seconds later. The `ApplicantManageFormPage` was opened, `reg_number`, `sex`, `course1` and `date_of_birth` was edited and the ``start`` transition was selected. This was done in the same transaction. The time difference between both log entries is only 0.001s. Furthermore, a payment ticket was created and the payment approved. Then the applicant was set to ``sumitted``, a `course_admitted` was selected and the applicant subsequently admitted. The form was automatically locked (see time difference). A student container was created and filled with the data from the application record. Finally, the entire applicants container including its content was removed in the same transaction, see time diffence between the last two log entries.


students.log
============


payments.log
============


hostels.log
===========




.. _regular expressions: http://en.wikipedia.org/wiki/Regular_expression