In the past, we used a default canonifier, which removes everything that
looks like a timestamp from log files. The goal of this is to prevent
logs from changing, e.g., due to local system times ending up in log
files.
This, however, also has the side-effect of removing information that is
parsed from protocols which probably should be part of our tests.
There is at least one test (1999 certificates) where the entire test
output was essentially removed by the canonifier.
GH-4521 was similarly masked by this.
This commit changes the default canonifier, so that only the first
timestamp in a line is removed. This should skip timestamps that are
likely to change while keeping timestamps that are parsed
from protocol information.
A pass has been made over the tests, with some additional adjustments
for cases which require the old canonifier.
There are some cases in which we probably could go further and not
remove timestamps at all - that, however, seems like a follow-up
project.
When looking up the postprocessor function from shadow files, id::find_func()
would abort() if the function wasn't available instead of falling back
to the default postprocessor.
Fix by using id::find() and checking the type explicitly and also adding a
strict type check while at it.
This issue was tickled by loading the json-streaming-logs package,
Zeek creating shadow files containing its custom postprocessor function,
then restarting Zeek without the package loaded.
Closes#4562
* origin/topic/johanna/sqlite-pragmas:
Options for SQLite log writer, eliminate duplicate definitions
Test synchronous/journal mode options for SQLite log writer
Added default options for synchronous and journal mode
Support for synchronous and journal_mode
With a bit of tweaking in the JavaScript plugin to support opaque types, this
will allow the delay functionality to work there, too.
Making the LogDelayToken an actual opaque seems reasonable, too. It's not
supposed to be user inspected.
This is a verbose, opinionated and fairly restrictive version of the log delay idea.
Main drivers are explicitly, foot-gun-avoidance and implementation simplicity.
Calling the new Log::delay() function is only allowed within the execution
of a Log::log_stream_policy() hook for the currently active log write.
Conceptually, the delay is placed between the execution of the global stream
policy hook and the individual filter policy hooks. A post delay callback
can be registered with every Log::delay() invocation. Post delay callbacks
can (1) modify a log record as they see fit, (2) veto the forwarding of the
log record to the log filters and (3) extend the delay duration by calling
Log::delay() again. The last point allows to delay a record by an indefinite
amount of time, rather than a fixed maximum amount. This should be rare and
is therefore explicit.
Log::delay() increases an internal reference count and returns an opaque
token value to be passed to Log::delay_finish() to release a delay reference.
Once all references are released, the record is forwarded to all filters
attached to a stream when the delay completes.
This functionality separates Log::log_stream_policy() and individual filter
policy hooks. One consequence is that a common use-case of filter policy hooks,
removing unproductive log records, may run after a record was delayed. Users
can lift their filtering logic to the stream level (or replicate the condition
before the delay decision). The main motivation here is that deciding on a
stream-level delay in per-filter hooks is too late. Attaching multiple filters
to a stream can additionally result in hard to understand behavior.
On the flip side, filter policy hooks are guaranteed to run after the delay
and can be used for further mangling or filtering of a delayed record.
This field isn't required by a worker and it's certainly not used by a
worker to listen on that specific interface. It also isn't required to
be set consistently and its use in-tree limited to the old load-balancing
script.
There's a bif called packet_source() which on a worker will provide
information about the actually used packet source.
Relates to zeek/zeek#2877.
Unsure what it's used for today and also results in the situation that on
some platforms we generate a reporter.log in bare mode, while on others
where spicy is disabled, we do not.
If we want base/frameworks/version loaded by default, should put it into
init-bare.zeek and possibly remove the loading of the reporter framework
from it - Reporter::error() would still work and be visible on stderr,
just not create a reporter.log.
This new table provides a mechanism to add environment variables to the
postprocessor execution. Use case is from ZeekControl to inject a suffix
to be used when running with multiple logger.
While working on a rotation format function, ran into Zeek crashing
when not returning a value from it, fix and recover the same way as
for scripting errors.
This adds one metric per log stream and one metric per log writer (path based)
to track the number of writes on a stream level as well as on a writer level.
$ curl -sSf localhost:8181/metrics | grep Conn
zeek_log_writer_writes_total{endpoint="",filter-name="default",module="HTTP",path="http",stream="HTTP::LOG",writer="Log::WRITER_SQLITE"} 1 1677497572770
zeek_log_stream_writes_total{endpoint="",module="HTTP",stream="HTTP::LOG"} 1 1677497572770
The initial version of this change also included metrics around log
write vetoes, but given no log policies exist in the default configuration
and they are mostly interesting for a few streams/writers only, skip this
for now. These can always be added by the script writer, too.
The difference between the stream level writes and concrete writers can
be used to deduce the number of vetoes (or errors) as a starting point.
This avoids interference from other log streams in the policy hook test cases,
which could cause deviations in output vs baselines depending on build
configuration.
As initial examples, this branch ports the Syslog and Finger analyzers
over. We leave the old analyzers in place for now and activate them
iff we compile without any Spicy.
Needs `zeek-spicy-infra` branches in `spicy/`, `spicy-plugin/`,
`CMake/`, and `zeek/zeek-testing-private`.
Note that the analyzer events remain associated with the Spicy plugin
for now: that's where they will show up with `-NN`, and also inside
the Zeekygen documentation.
We switch CMake over to linking the runtime library into the plugin,
vs. at the top-level through object libraries.
This commit adds an optional event_groups field to the Logging::Stream record
to associated event groups with logging streams.
This can be used to disable all event groups of a logging stream when it is
disabled. It does require making an explicit connection between the
logging stream and the involved groups, however.
Now that it's loaded in bare mode, no need to load it explicitly.
The main thing that tests were relying on seems to be tracking of
c$service for conn.log baselines. Very few were actually checking
for dpd.log
Observed .sqlite-journal files and missing reporter.sqlite files
in CI runs. Subsequently reading the ./test.sqlite file is more
reliable and should be good enough.
Also modify FormatRotationPath to keep rotated logs within
Log::default_logdir unless the rotation function explicitly
set dir, e.g. by when the user redef'ed default_rotation_interval.
With the introduction of LogAscii::logdir, log filenames can now include
parent directories rather than being plain basenames. Enabling log rotation,
leftover log rotation and setting LogAscii::logdir broke due to not
handling this situation.
This change ensures that .shadow files are placed within the directory where
the respective .log file is created. Previously, the .shadow. (or .tmp.shadow.)
prefix was simply prepended, yielding non-sensical paths such as
.tmp.shadow.foo/bar/packet_filter.log for a logdir of foo/bar.
Additionally, respect LogAscii::logdir when searching for leftover log files
rather than defaulting to the current working directory.
The following quirk exist around LogAscii::logdir, but will be addressed
in a follow-up.
* By default, logs are currently rotated into the working directory of the
process, rather than staying confined within LogAscii::logdir. One of
the added tests shows this behavior.
Due to a bug (or intentional code) in SQLite, we disabled enabling the shared cache
in sqlite3 if running under ThreadSanitizer (see cf1fefbe0b0a6163b389cc92b5a6878c7fc95f1f).
Unfortunately, this has the side-effect of breaking the simultaneous-writes test because
the shared cache is disabled. This is hopefully a temporary fix until SQLite fixes the
issue on their side.
This addresses the need for a central hook on any log write, which
wasn't previously doable without a lot of effort. The log manager
invokes the new Log::log_stream_policy hook prior to any filter-specific
hooks. Like filter-level hooks, it may veto a log write. Even when
it does, filter-level hooks still get invoked, but cannot "un-veto".
Includes test cases.
* 'logging/script-logdir' of https://github.com/kramse/zeek:
Copy of ascii-empty test, just changed path in the beginning
Logdir: Change requested by 0xxon, no problem
Introduce script-land variable that can be used to set logdir.
Closes GH-772
