The action log

The action log is part of the Session History. Where the Profiling information and errors as data provide deep insight into an incident, the action log provides insight into what happened before.

The action log is like any other log file, it contains the output of tracing statements. The GuardServersession library manages these log files.

The action log is stored in .actionLog files in the sub folder tracings of the project folder. At the end of a solver session saved in AIMMS PRO storage at /userdata/<env>/<user>/<appname>/tracings/<session-id>.actionLog.

The following is a sample small action log:

Opening log file tracings/d942c7adf9460ee3f4f2a0de1ed0833b.actionLog at 2021-03-08 14:25:20
This file contains the log of a data session on behalf of chris@AIMMS
2021-03-08 14:25:24:72 [info ] Enter pr_btnSolve() [51.125 Mb] in use
2021-03-08 14:25:27:55 [debug] Enter gss::LoadResultsCallBack() [51.457 Mb] in use
2021-03-08 14:25:27:60 [trace] s_trackedSessions = { d942c7adf9460ee3f4f2a0de1ed0833b, c78864a3-babf-4015-ae41-38de854fa0a3 }
2021-03-08 14:25:27:61 [debug] Leave gss::LoadResultsCallBack() [51.770 Mb] in use. Duration is 0.060 [seconds] and memory increase is 0.313 Mb.
2021-03-08 14:25:27:62 [warn ] 2021-03-08 14:25:24:00: Warning: Don't look down.
2021-03-08 14:25:27:62 [warn ] 2021-03-08 14:25:27:00: Warning: Look up, it is raining ;-).
2021-03-08 14:25:27:63 [info ] Leave pr_btnSolve() [51.895 Mb] in use. Duration is 2.910 [seconds] and memory increase is 0.770 Mb.

Remarks:

1. First two lines summarizing which session is logged.

2. The actual logging consists of three columns:

   1. Date time, since version 1.1.1, these time stamps are in timezone UTC

   2. Importance level of messages

   3. The actual message

3. [warn] Lines 7, 8: Warnings first issued, then handled. The timestamp in the date time column is the time the warning was handled. The timestamp in the message column is the timestamp the warning was created.

4. [info] Lines 3, 9: An action - a procedure invoked via the WebUI by the end-user. These lines are marked here.

5. [debug] Lines 4, 6: The procedure is invoked by program logic (call back server session).

6. [trace] Line 5: requesting and printing a bit of state is typically done at message importance level 'trace'

Relevant identifiers for logging

1. Set gss::s_messageLevels

   Set s_messageLevels {
       Index: i_messageLevel;
       Definition: {
           data { trace, debug, info, warn, error, fatal } ;
       }
       Comment: "The message levels for tracing""}
   

   Here the message level 'trace' is the lowest level, and the level 'fatal' is the highest level.

2. Element parameter gss::ep_tracingFilterlevel with range gss::s_messageLevels

   The tracing filter level: any log message with importance below this filter level will not be logged. At the beginning of a session, this parameter is initialized to ‘info’. So when this tracing filter level is kept at its default, messages with importance ‘debug’ or ‘trace’ will not be logged.

   Note

   1. This parameter is part of the input case sent from the data session to a solver session. Therefore, setting the logging level in the data session will affect the logging in the solver sessions.

   2. At the beginning of a session, this parameter is initialized to 'info'. So when this tracing filter level is kept at its default, messages with importance 'debug' or 'trace' will not be logged.

3. Procedure gss::pr_setTracinglevel(ep_newTracingFilterLevel)

   Use this procedure to set the gss::ep_tracingFilterlevel

   Arguments:

   1. Element parameter ep_newTracingFilterLevel, with range gss::s_messageLevels

   Throws exceptions: None

   Return value: None.

4. Procedure gss::pr_logMsg(sp_message,ep_messageImportance)

   Writes sp_message to the action log file provided the importance of the message ep_messageImportance is greater than or equal to message filter level ep_tracingFilterlevel

   Arguments:

   1. sp_message An input string parameter.

   2. ep_messageImportance An optional element parameter with range s_MessageLevels and default 'trace'.

   Throws exceptions: None.

   Return value: None.

5. Procedure gss::pr_enter(sp_procEnterTimestamp,p_procEnterMemoryInUse,ep_messageImportance,sp_logDetail)

   Log the entry of a procedure, including when the procedure was entered and how much memory was in use. In addition, it stores the entry time and the memory in use at entry in the output arguments sp_procEnterTimestamp and p_procEnterMemoryInUse.

   The techniques used by gss::pr_enter and gss::pr_leave are laid out in Tracing .

   Arguments:

   1. sp_procEnterTimestamp An output parameter that contains the encompassing procedure entry time according to timezone 'UTC'

   2. p_procEnterMemoryInUse An output parameter that contains the amount of memory in use upon when the encompassing procedure was entered.

   3. ep_messageImportance optional default 'debug' The importance of logging the entry of the encompassing procedure. For procedures that are actions, it is recommended to use the value 'info'.

   4. sp_logDetail optional, default: empty

   Throws exceptions: None

   Return value: None.

6. Procedure gss::pr_leave(sp_procEnterTimestamp,p_procEnterMemoryInUse,ep_messageImportance,sp_logDetail)

   1. sp_procEnterTimestamp An input parameter that contains the encompassing procedure entry time according to timezone 'UTC'

   2. p_procEnterMemoryInUse An input parameter that contains the amount of memory in use upon when the encompassing procedure was entered.

   3. ep_messageImportance optional default 'debug' The importance of logging the leaving of the encompassing procedure. For procedures that are actions, it is recommended to use the value 'info'.

   4. sp_logDetail optional, default: empty

   Throws exceptions: None

   Return value: None.

7. Procedure pr_setReplicationSessionLog(bp_doReplicate)

   This procedure allows you to turn on/off replication of the action log to the session log.

   Arguments:

   1. bp_doReplicate When 1, the action log will be replicated from the action to the session log.

8. Set gss::s_Settings

   Elements:

   1. DownloadFolder: Override for the download folder to be used when the WinUI downloads an incident summary.

9. Procedure gss::pr_setSetting(ep_setting,sp_value)

   Set the setting ep_setting to value sp_value

10. Procedure gss::pr_getSetting(ep_setting,sp_value)

    Retrieve the setting ep_setting and store in sp_value

Recommended use

Important to what has been done, is a list of actions. Here an action is defined as: An AIMMS procedure that is invoked via the WebUI. Examples of invocations of procedures from the WebUI are:

1. Button press

2. Uponchange procedure of a data item

3. A menu entry, via an item menu, widget menu, primary action, or secondary action

4. Status bar procedure

5. Page property: Action upon load

6. Page property: Action upon leave

By having a complete log of actions of an end-user; one can try to replay what happened.

For actions, please follow the following template:

Procedure pr_actionTemplate {
    Body: {
        pr_enter(sp_gssTime, p_gssMiU, ep_messageImportance: 'info');
        block
            ! Call procedure to do the actual work.
        onerror ep_err do
            gss::pr_appendError( ep_err );
            errh::MarkAsHandled( ep_err );
        endblock ;
        pr_leave(sp_gssTime, p_gssMiU, ep_messageImportance: 'info');
    }
    Comment: "Sample action procedure""    DeclarationSection gss_logging_declarations {
        StringParameter sp_gssTime;
        Parameter p_gssMiU;
    }
    DeclarationSection error_reference_declaration {
        ElementParameter ep_err {
            Range: errh::PendingErrors;
        }
    }
}