Commit | Line | Data |
4536f655 |
1 | |
2 | Stem Logging Design |
3 | |
4 | The Stem logging subsystem is designed to be very flexible, powerful and |
5 | yet simple to use. Log data comes into the system via a Log Entry which |
6 | is submitted to Logical Logs. Entries can be submitted to multiple |
7 | Logical Logs which can be local to the current Hub or on remote |
8 | Hubs. Each Logical Log processes the Entry which can be filtered, |
9 | redirected and written to physical log files. Logical Log filter rules |
10 | can match the text or label with regular expressions, test the range or |
11 | value of the level, check the time of day or do any boolean combination |
12 | of those. If an Entry passes a set of rules, then it is passed to a set |
13 | of actions which can execute a wide range of operations upon it |
14 | including printing the entry to a file, sending it via email or to a |
15 | pager, printing it to stderr, or the entry can be forwarded to other |
16 | Logical Logs. The full set of filter rules and actions are described |
17 | below. |
18 | |
19 | Log Entries are constructed with the 'new' method of the |
20 | Stem::Log::Entry class. The caller can set the entry's text, label, and |
21 | a severity level and the timestamp is automatically stored in the |
22 | entry. If any Logical Logs are specified the entry is submitted to |
23 | them. In any case, the entry object is returned and it can be submitted |
24 | to Logical Logs with its submit method. The class Stem::Log::Entry is |
25 | registered as a Cell so Log Entries that are forwarded from remote Hubs |
26 | can be handled by this class. Log Entries can be created by created and |
27 | submitted by code anywhere in Stem. Many Cells can be configured to |
28 | submit Log Entries which contain data or status information. The |
29 | Debug/Trace subsystem also generates Log Entries as do any monitoring |
30 | modules such as Stem::LogTail. |
31 | |
32 | |
33 | A Logical Log is constructed by the 'new' method of the Stem::Log |
34 | class. They are typically created by external configurations but some |
35 | modules create them internally for their own use. Each Logical Log on a |
36 | Hub must have a unique name and that is the name used to submit Log |
37 | Entries. Remote Logical Logs are referred to by a string of the form |
38 | 'Hub:LogName'. Any place where you can specify a Logical Log name, you |
39 | can also use a remote Log name. |
40 | |
41 | When a Log Entry is submitted to a Logical Log it gets filtered and |
42 | processed. The Logical Log is configured with optional physical file and |
43 | filter attributes. If there is no filter in a Logical Log, its default |
44 | is to print any submitted Entries to its file (if there is one). Logical |
45 | Logs don't need to have a physical file attribute as they can filter and |
46 | print their Entries to many other possible destinations (see below for a |
47 | list of actions and Entry destinations). |
48 | |
49 | The 'path' attribute of a Logical Log specifies its file. Other |
50 | attributes control the long term management of the file. They include |
51 | when to rotate the log file, the format of the timestamp suffix of the |
52 | rotated files, any compression to be performed, where to move archived |
53 | logs, eternal programs to be called to process the log file, etc. These |
54 | log file handling attributes and their code support are under development. |
55 | |
56 | The filter attribute of a Logical Log consists of a set of key/value |
57 | pairs which are called filter operations. When an Entry is submitted to |
58 | a Logical Log which has a filter, a private hash copy of all of its data |
59 | is made and a special boolean called the filter flag is set in that |
60 | hash. All of the filter operations are processed sequentially and work |
61 | with that flag. The operations can be grouped into 3 types, flag |
62 | operations, rules and actions. Flag operations directly modify the |
63 | filter flag and its behavior which is used to control the rules and |
64 | actions of this filter. Rules are boolean tests that check the submitted |
65 | entry for some condition and can set or clear the filter flag. Actions |
66 | print or forward the submitted Entry only if the filter flag is |
67 | currently true. The filter flag is initialized to true so all actions |
68 | and rules will be executed until some rule or flag operation clears it. |
69 | |
70 | Flag operations are always executed regardless of the current value of |
71 | the filter flag. The current value of the filter flag can be set, |
72 | cleared or inverted. Also the boolean operation that is used with the |
73 | rules can be selected. It defaults to 'and' which causes each rule's |
74 | boolean result to be 'and'ed with the filter flag and stored there. If |
75 | the flag operator is set to 'or', then the rule result is or'ed with the |
76 | flag and stored back into it. The boolean test of the filter flag can be |
77 | inverted with the 'invert_test' flag operation. By combining the flag |
78 | operations and the negated prefix of rules (see below) you can get any |
79 | boolean combination of rules. If you want multiple sets of rules each |
80 | with their own set of actions in a filter, just set the filter flag to |
81 | true before each set of rules and follow them by their associated |
82 | actions. If you want to execute some actions if any of a set of rules is |
83 | true, set the filter flag to false, set the flag operation to 'or' and |
84 | set the test to inverted. The next rules will execute since the test in |
85 | inverted and the flags is false. If any rule returns true, it will will |
86 | set the flag since it is 'or'ed with it. The rest of the rules will be |
87 | skipped. Then the normal_test operation should be executed. The actions |
88 | that follow will only be executed if any rule was true. |
89 | |
90 | Filter rules are only executed if the filter flag is currently true (or |
91 | false when the inverted_flag operation is in effect). Each filter rule |
92 | name can be prefixed with 'not_' which will invert the results of the |
93 | rule. There are many builtin rules which are grouped into three |
94 | categories. The first group matches either an Entry label or text with a |
95 | regular expression. The second group compares the Entry severity level |
96 | with an integer. The third group compares the Entry severity level with |
97 | a global value in the %Stem::Vars::Env hash. Those hash values can |
98 | be set on the command line, from environment variables and by code. This |
99 | allows for fine control of how Entries get filtered by level. Examples |
100 | of using that facility are to enable debug/trace calls to output to |
101 | stderr or be forwarded to a remote Logical Log. |
102 | |
103 | Filter actions, like filter rules are only executed if the filter flag |
104 | is currently true (or false when the inverted_flag operation is in |
105 | effect). But actions cannot affect the value of the filter flag and are |
106 | meant to send Log Entries to different destinations. The builtin actions |
107 | can print Log Entries to stdout, stderr or the controlling TTY. Entries |
108 | can be emailed, sent to a pager, written to the console with the wall or |
109 | write commands, or forwarded to other Logical Logs. Of course they also |
110 | can be written the to physical file associated with this Logical Log. |
111 | |
112 | WARNING: Currently forwarding loops can be created with Log filter |
113 | actions. There are plans to detect them with either storing in the Log |
114 | Entry a hop count or a history of which Logical Logs it has seen. |
115 | |
116 | Custom filter rules and actions can also be created. Any module can have |
117 | them and they are called by their name which is the value of the |
118 | 'custom' operation. The difference between a custom rule and action is |
119 | that the rules return a defined boolean value while the actions return |
120 | the undefined value (a plain return does that). |
121 | |
122 | When a Log Entry needs to printed by an action (which all builtin ones |
123 | except forwarding does), it must format the Entry. This is controlled by |
124 | the 'format' attribute of the Logical Log. The format value is similar |
125 | to sprintf and uses % as a field marker. It can print the Entry text |
126 | (%T), label (%L), level (%l), timestamp (%l) and original Logical Log |
127 | name (%N) (so forwarded Log Entries can say where they came from). The |
128 | default Log Entry format is %T which will just print the text. Also the |
129 | timestamp which is normally printed as an integer (Unix Epoch time) can |
130 | be printed with the %f marker in a strftime format. The attribute which |
131 | controls the time format is 'strftime'. The default strftime format is |
132 | %C which will print the time as the command 'date' will. |
133 | |