As mtail
is designed to tail log files and apply regular expressions to new
log lines to extract data, the language naturally follows this pattern-action
style.
It resembles another, more famous pattern-action language, that of AWK.
This page errs on the side of a language specification and reference. See the
Programming Guide for a gentler introduction to writing
mtail
programs.
mtail
runs all programs on every line received by the log tailing subsystem.
The rough model of this looks like:
for line in lines:
for regex in regexes:
if match:
do something
Each program operates once on a single line of log data, and then terminates.
An mtail
program consists of exported variable definitions, pattern-action
statements, and optional decorator definitions.
exported variable
pattern {
action statements
}
def decorator {
pattern and action statements
}
mtail
's purpose is to extract information from logs and deliver them to a
monitoring system. Thus, variables must be named for export.
Variables, which have type counter
or gauge
, must be declared before their
use.
counter lines_total
gauge queue_length
They can be exported with a different name, with the as
keyword, if one wants
to use characters that would cause a parse error. This example causes the metric
to be named line-count
in the collecting monitoring system.
counter lines_total as "line-count"
Variables can be dimensioned with one or more axes, with the by
keyword,
creating multidimensional data. Dimensions can be used for creating histograms,
as well.
counter bytes by operation, direction
counter latency_ms by bucket
Putting the hidden
keyword at the start of the declaration means it won't be
exported, which can be useful for storing temporary information. This is the
only way to share state between each line being processed.
hidden counter login_failures
mtail
programs look a lot like awk
programs. They consist of a conditional
expression followed by a brace-enclosed block of code:
COND {
ACTION
}
COND
is a conditional expression. It can be a regular expression, which if
matched enters the action block, or a relational expression as you might
encounter in a C program's if
statement (but without the if
, it is
implicit.)
/foo/ {
ACTION1
}
variable > 0 {
ACTION2
}
/foo/ && variable > 0 {
ACTION3
}
In the above program, ACTION1 is taken on each line input if that line matches
the word foo
, and ACTION2 is taken on each line if when that line is read, the
variable variable
is greater than 0. ACTION3 occurs if both are true.
The action statements must be wrapped in curly braces, i.e. {}
. mtail
programs have no single-line statement conditionals like C.
mtail
supports RE2-style regular expression syntax, but is limited by what is
supported by the Go implementation of Go's
regexp/syntax.
To re-use parts of regular expressions, you can assign them to a const
identifier:
const PREFIX /^\w+\W+\d+ /
PREFIX {
ACTION1
}
PREFIX + /foo/ {
ACTION2
}
In this example, ACTION1 is done for every line that starts with the prefix regex, and ACTION2 is done for the subset of those lines that also contain 'foo'.
Pattern fragments like this don't need to be prefixes, they can be anywhere in the expression.
counter maybe_ipv4
const IPv4 /(?P<ip>\d+\.\d+\.\d+\.\d+)/
/something with an / + IPv4 + / address/ {
maybe_ipv4++
}
See dhcpd.mtail for more examples of this.
See also the section on decorators below for improving readability of expressions that are only matched once.
More complex expressions can be built up from relational expressions and other pattern expressions.
The following relational operators are available in mtail
:
<
less than<=
less than or equal>
greater than>=
greater than or equal==
is equal!=
is not equal=~
pattern match!~
negated pattern match||
logical or&&
logical and!
unary logical negation
The following arithmetic operators are available in mtail
:
|
bitwise or&
bitwise and^
bitwise xor+
addition-
subtraction*
multiplication/
division<<
bitwise shift left>>
bitwise shift right**
exponent
The following arithmetic operators act on exported variables.
=
assignment++
increment+=
increment by--
decrement
When a conditional expression does not match, action can be taken as well:
/foo/ {
ACTION1
} else {
ACTION2
}
Else clauses can be nested. There is no ambiguity with the dangling-else
problem, as mtail
programs must wrap all block statements in {}
.
The otherwise
keyword can be used as a conditional statement. It matches if no
preceding conditional in the current scope has matched. This behaves similarly
to the default
clause in a C switch
statement.
/foo/ {
/foo1/ {
ACTION1
}
/foo2/ {
ACTION2
}
otherwise {
ACTION3
}
}
In this example, ACTION3 will be executed if neither /foo1/
or /foo2/
match
on the input, but /foo/
does.
The simplest mtail
program merely counts lines read:
/$/ {
lines_total++
}
This program instructs mtail
to increment the lines_total
counter variable on
every line received (specifically anytime an end-of-line is matched.)
Regular expressions in patterns can contain capture groups -- subexpressions wrapped in parentheses. These can be referred to in the action block to extract data from the line being matched.
For example, part of a program that can extract from rsyncd
logs may want to
break down transfers by operation and module.
counter transfers_total by operation, module
/(?P<operation>\S+) (\S+) \[\S+\] (\S+) \(\S*\) \S+ (?P<bytes>\d+)/ {
transfers_total[$operation][$3]++
}
Or, the value of the counter can be increased by the value of a capture group:
counter bytes_total by operation, module
/(?P<operation>\S+) (\S+) \[\S+\] (\S+) \(\S*\) \S+ (?P<bytes>\d+)/ {
bytes_total[$operation][$3] += $bytes
}
Numeric capture groups address subexpressions in the match result as you might
expect from regular expression groups in other languages, like awk and perl --
e.g. the expression $3
refers to the third capture group in the regular
expression.
Named capture groups can be referred to by their name as indicated in the
regular expression using the ?P<name>
notation, as popularised by the Python
regular expression library -- e.g. $bytes
refers to (?P<bytes>\d+)
in the
examples above.
Capture groups can be used in the same expression that defines them, for example
in this expression that matches and produces $x
, then compares against that
value.
/(?P<x>\d+)/ && $x > 1 {
nonzero_positives++
}
It is also useful to timestamp a metric with the time the application thought an
event occurred. Logs typically prefix the log line with a timestamp string,
which can be extracted and then parsed into a timestamp internally, with the
strptime
builtin function.
A regular expression that extracts the timestamp in boring old syslog format looks like:
/^(?P<date>\w+\s+\d+\s+\d+:\d+:\d+)/ {
strptime($date, "Jan 02 15:04:05")
...
}
Buyer beware! The format string used by mtail
is the same as the Go
time.Parse() format string, which is completely
unlike that used by C's strptime. The format string must always be the 2nd of
January 2006 at 3:04:05 PM. See the documentation for the ANSIC format in
the above link for more details. NOTE that unlike Go's time.Parse()
(and
like C's) the format string is the second argument to this builtin function.
NOTE: without a
strptime()
call,mtail
will default to using the current system time for the timestamp of the event. This may be satisfactory for near-real-time logging.
It is of course possible to nest more pattern-actions within actions. This lets you factor out common parts of a match expression and deal with per-message actions separately.
For example, parsing syslog timestamps is something you may only wish to do once, as it's expensive to match (and difficult to read!)
counter foo
counter bar
/^(?P<date>\w+\s+\d+\s+\d+:\d+:\d+)/ {
strptime($date, "Jan 02 15:04:05")
/foo/ {
foo++
}
/bar/ {
bar++
}
}
This will result in both foo and bar counters being timestamped with the current log line's parsed time, once they match a line.
Decorated actions are an inversion of nested actions. They allow the program to define repetitive functions that perform the same extraction across many different actions.
For example, most log file formats start with a timestamp prefix. To reduce
duplication of work, decorators can be used to factor out the common work of
extracting the timestamp. For example, to define a decorator, use the def
keyword:
def syslog {
/(?P<date>\w+\s+\d+\s+\d+:\d+:\d+)/ {
strptime($date, "Jan 2 15:04:05")
next
}
}
The decorator definition starts and ends in a curly-braced block, and looks like
a normal pattern/action as above. The new part is the next
keyword, which
indicates to mtail
where to jump into the decorated block.
To use a decorator:
@syslog {
/some event/ {
variable++
}
}
The @
notation, familiar to Python programmers, denotes that this block is
"wrapped" by the syslog
decorator. The syslog decorator will be called on each
line first, which extracts the timestamp of the log line. Then, next
causes
the wrapped block to execute, so then mtail
matches the line against the
pattern some event
, and if it does match, increments variable
.
mtail
metrics have a kind and a type. The kind affects how the metric is recorded, and the type describes the data being recorded.
Ordinarily mtail
doesn't treat kinds specially, except when they are being exported.
counter
assumes that the variable is a monotonically increasing measure, so that computations on sampled data like rates can be performed without loss. Use for counting events or summing up bytes transferred.gauge
assumes that the variable can be set to any value at any time, signalling that rate computations are risky. Use for measures like queue length at a point in time.histogram
is used to record frequency of events broken down by another dimension, for example by latency ranges. This kind does have special treatment withinmtail
.
The second dimension is the internal representation of a value, which is used by
mtail
to attempt to generate efficient bytecode.
- Integer
- Float
- Bool
- String
Some of these types can only be used in certain locations -- for example, you
can't increment a counter by a string, but mtail
will fall back to a attempt
to do so, logging an error if a runtime type conversion fails. Likewise, the
only type that a histogram
can observe is a Float.
These types are usually inferred from use, but can be influenced by the programmer with builtin functions. Read on.
mtail
contains some builtin functions for help with extracting information and
manipulating state.
There are "pure" builtin functions, in that they have no side effects on the program state.
-
len(x)
, a function of one string argument, which returns the length of the string argumentx
. -
tolower(x)
, a function of one string argument, which returns the inputx
in all lowercase. -
subst(old, new, val)
, a function of three arguments which returns the inputval
with all substrings or patternsold
replaced bynew
. When given a string forold
, it is a direct proxy of the Go strings.ReplaceAll function.subst("old", "new", $val)
When given a regular expression pattern for
old
, it uses regexp.ReplaceAllLiteralString.subst(/old/, "new", $val)
Note the different quote characters in the first argument.
There are type coercion functions, useful for overriding the type inference made by the compiler if it chooses badly. (If the choice is egregious, please file a bug!)
int(x)
, a function of one argument performs type conversion to integer. Ifx
is a type that can be converted to integer, it does so. If the type ofx
cannot be converted to an integer, a compile error is triggered. If the value ofx
cannot be converted to an integer, then a runtime error is triggered.float(x)
, a function of one argument that performs type conversion to floating point numbers. The same rules apply as forint()
above.string(x)
, a function of one argument that performs conversion to string values.strtol(x, y)
, a function of two arguments, which converts a stringx
to an integer using basey
. Useful for translating octal or hexadecimal values in log messages.
A few builtin functions exist for manipulating the virtual machine state as side effects for the metric export.
getfilename()
, a function of no arguments, which returns the filename from which the current log line input came.settime(x)
, a function of one integer argument, which sets the current timestamp register.strptime(x, y)
, a function of two string arguments, which parses the timestamp in the stringx
with the parse format string iny
, and sets the current timestamp register. The parse format string must follow Go's time.Parse() format stringtimestamp()
, a function of no arguments, which returns the current timestamp. This is undefined if neithersettime
orstrptime
have been called previously.
The current timestamp register refers to mtail
's idea of the time
associated with the current log line. This timestamp is used when the variables
are exported to the upstream collector. The value defaults to the time that the
log line arrives in mtail
, and can be changed with the settime()
or
strptime()
builtins.
User defined functions are not supported, but read on to Decorated Actions for how to reuse common code.
By limiting the pattern of a capturing group to only numeric characters, the
programmer can provide hints to mtail
about the type of an expression. For
example, in the regular expression
/(\d+)/
the first capture group can only match digits, and so the compiler will infer that this is an integer match.
/(\d+\.\d+)/
looks like it matches floating point numbers, and so the compiler will infer that this is of type float.
NOTE: In the expression above, the dot is escaped. A regular expression operator
.
matches every character and so the inference assumes that the type of '.' is a string.
The compiler performs type inference on the expressions that use the capture groups, and the metrics they are ultimately assigned to, and will assign a type (either integer or floating point) to the metrics exported.
Thus in a program like:
gauge i
gauge f
/(\d+)/ {
i = $1
}
/(\d+\.\d+)/ {
f = $1
}
the metric i
will be of type Int and the metric f
will be of type Float.
The advantage of limiting pattern matches to specific values is that mtail
can
generate faster bytecode if it knows at compile-time the types to expect. If
mtail
can't infer the value types, they default to String
and mtail
will
attempt a value conversion at runtime if necessary. Runtime conversion errors
will be emitted to the standard INFO log, and terminate program execution for
that log line.
mtail
performs no implicit garbage collection in the metric storage. The
program can hint to the virtual machine that a specific datum in a dimensioned
metric is no longer going to be used with the del
keyword.
gauge duration by session
hidden session_start by session
/end/ {
duration[$session] = timestamp() - session_start[$session]
del session_start[$session]
}
In this example, a hidden metric is used to record some internal state. It will
grow unbounded as the number of sessions increases. If the programmer knows that
the /end/
pattern is the last time a session will be observed, then the datum
at $session
will be freed, which keeps mtail
memory usage under control and
will improve search time for finding dimensioned metrics.
del
can be modified with the after
keyword, signalling that the metric
should be deleted after some period of no activity. For example, the
expression
del session_start[$session] after 24h
would mean that the datum indexed by $session
will be removed 24 hours after the last update is recorded.
The del-after form takes any time period supported by the go
time.ParseDuration
function.
Expiry is only processed once ever hour, so durations shorter than 1h won't take effect until the next hour has passed.
This command only makes sense for dimensioned metrics.
A size limit can be specified on a metric with the modifier limit
.
counter bytes_total by operation limit 500
When the garbage collection run encounters a variable with size limit that is over its size limit, it will remove the oldest values until the whole metric is below its limit again. Oldest values are chosen by the timestamp of the datum.
This modifier only makes sense for dimensioned metrics.
The program runs from start to finish once per line, but sometimes you may want to stop the program early. For example, if the log filename does not match a pattern, or some stateful metric indicates work shouldn't be done.
For this purpose, the stop
keyword terminates the program immediately.
The simplest and most useless mtail program is thus:
stop
But for more useful situations, perhaps stopping if the log filename doesn't match a pattern:
getfilename() !~ /apache.access.log/ {
stop
}