...with this change, it'll be possible to identify WriterFrontend's
based on (stream, filter_name, path) pairs in addition to (stream,
writer, path) pairs.
Log flushing is currently triggered based on the threading heartbeat timer
of WriterBackends and the hard-coded WRITE_BUFFER_SIZE 1000.
This change introduces a separate timer that is managed by the logger
manager instead of piggy-backing on the heartbeat timer, as well as a
const &redef for the buffer size.
This allows to modify the log flush frequency and batch size independently
of the threading heartbeat interval. Later, this will allow to re-use the
buffering and flushing logic of writer frontends for non-Broker cluster
backends, too.
One change here is that even frontends that do not have a backend will
be flushed regularly. This is wanted for non-Broker backends and should be
very cheap. Possibly, Broker can piggy back on this timer down the road, too,
rather than using its own script-level timer (see Broker::log_flush()).
This allows to leverage automatic memory management, less allocations
and using move semantics for expressing ownership.
This breaks the existing logging and broker API, but keeps the plugin
DoWrite() and HookLogWrite() methods functioning.
It further changes ValToLogVal to return a threading::Value rather than
a threading::Value*. The vector_val and set_val fields unfortunately
use the same pointer-to-array-of-pointers approach. this can'tbe changed
as it'd break backwards compatibility for plugin provided input readers
and log writers.
This largely copies over Spicy's `.clang-format` configuration file. The
one place where we deviate is header include order since Zeek depends on
headers being included in a certain order.
The Zeek code base has very inconsistent #includes. Many sources
included a few headers, and those headers included other headers, and
in the end, nearly everything is included everywhere, so missing
#includes were never noticed. Another side effect was a lot of header
bloat which slows down the build.
First step to fix it: in each source file, its own header should be
included first to verify that each header's includes are correct, and
none is missing.
After adding the missing #includes, I replaced lots of #includes
inside headers with class forward declarations. In most headers,
object pointers are never referenced, so declaring the function
prototypes with forward-declared classes is just fine.
This patch speeds up the build by 19%, because each compilation unit
gets smaller. Here are the "time" numbers for a fresh build (with a
warm page cache but without ccache):
Before this patch:
3144.94user 161.63system 3:02.87elapsed 1808%CPU (0avgtext+0avgdata 2168608maxresident)k
760inputs+12008400outputs (1511major+57747204minor)pagefaults 0swaps
After this patch:
2565.17user 141.83system 2:25.46elapsed 1860%CPU (0avgtext+0avgdata 1489076maxresident)k
72576inputs+9130920outputs (1667major+49400430minor)pagefaults 0swaps
Broker had changed the semantics of remote logging: it sent over the
original Bro record containing the values to be logged, which on the
receiving side would then pass through the logging framework normally,
including triggering filters and events. The old communication system
however special-cases logs: it sends already processed log entries,
just as they go into the log files, and without any receiver-side
filtering etc. This more efficient as it short-cuts the processing
path, and also avoids the more expensive Val serialization. It also
lets the sender determine the specifics of what gets logged (and how).
This commit changes Broker over to now use the same semantics as the
old communication system.
TODOs:
- The new Broker code doesn't have consistent #ifdefs yet.
- Right now, when a new log receiver connects, all existing logs
are broadcasted out again to all current clients. That doesn't so
any harm, but is unncessary. Need to add a way to send the
existing logs to just the new client.
Looks like the right fix. Two tiny tweaks:
- changed the order of arguments for DeleteVals() for consistency
with the corresponding Manager function.
- turned the InternalWarning into a Warning: if I understand
correctly, this can happen when scripts on nodes diverge; which
is a user-side problem, not an internal Bro logic issue.
BIT-1683 #merged
* origin/topic/johanna/bit-1683:
Actually check if the number of fields in a write are equal to the number of fields required.
number of fields required.
Addresses BIT-1683
I do not think this quite fixes the underlying issue of BIT-1683 - it
should not be possible to get to this state in normal operations.
Also fixes a small memory leak for disabled writers.
Seems to work, tests pass, but not really verified.
Major change 1:
finished flag in MsgThread was replaced by 2 flags:
child_finished and main_finished.
child_finished is set by child_thread and means that the processing
loop is stopped immediately (no longer needed, no new input messages
will be processed, if loop continues running there is an ugly delay
on shutdown). (This took me a while to realize...)
main_finished is set by a message that is sent back by the child
to the main thread when Finished() is called (and child_finished
is set). when main_finished is set, processing of output messages
stops. But all messages that the child thread pushed in the queue
before calling Finish() are still processed.
Change 2:
Logging terminate call was replaced by a smaller call that just
flushes out the cache held by the main thread. This call
has to be done before thread shutdown is called - otherwhise
the threads will be shut down before all messages are pushed
on them. (This also took me a while to realize...).
Change 3:
Input framework actually calls it stop methods correctly (everything
was prepared, function call was missing)
Once a BasicThread leaves its run() method, a thread is now marked for
cleaning up, and the ThreadMgr will soon join it to release the OS
resources.
Also, adding a function Log::remove_stream() that remove a logging
stream, stopping all writer threads that are associated with it.
Note, however, that removing a *filter* from a stream still doesn't
clean up any threads. The problem is that because of the output paths
potentially being created dynamically it's unclear if the writer
thread will still be needed in the future. We could add clean writers
up with timeouts, but that doesn't sound great either. So for now, the
only way to sure clean up logging threads is to remove the entire
stream.
Also note that cleanup doesn't work with input threads yet, which
don't seem to terminate (at least in the case I tried).
* topic/robin/master-test: (60 commits)
Script fix for Linux.
Updating test base line.
Another small change to MsgThread API.
Bug fix for BasicThread.
make version_ok return true for TLSv12
Sed usage in canonifier script didn't work on non-Linux systems.
Changing HTTP DPD port 3138 to 3128.
Temporarily removing tuning/logs-to-elasticsearch.bro from the test-all-policy.
More documentation updates.
Revert "Fixing calc_next_rotate to use UTC based time functions."
Some documentation updates for elasticsearch plugin.
Give configure a --disable-perftools option.
Updating tests for the #start/#end change.
Further threading and API restructuring for logging and input frameworks.
Reworking forceful thread termination.
Moving the ASCII writer over to use UNIX I/O rather than stdio.
Further reworking the thread API.
Reworking thread termination logic.
If a thread doesn't terminate, we log that but not longer proceed (because it could hang later still).
Removing the thread kill functionality.
...
frameworks.
There were a number of cases that weren't thread-safe. In particular,
we don't use std::string anymore for anything that's passed between
threads (but instead plain old const char*, with manual memmory
managmenet).
This is still a check-point commit, I'll do more testing.
Turns out the finish methods weren't called correctly, caused by a
mess up with method names which all sounded too similar and the wrong
one ended up being called. I've reworked this by changing the
thread/writer/reader interfaces, which actually also simplifies them
by getting rid of the requirement for writer backends to call their
parent methods (i.e., less opportunity for errors).
This commit also includes the following (because I noticed the problem
above when working on some of these):
- The ASCII log writer now includes "#start <timestamp>" and
"#end <timestamp> lines in the each file. The latter supersedes
Bernhard's "EOF" patch.
This required a number of tests updates. The standard canonifier
removes the timestamps, but some tests compare files directly,
which doesn't work if they aren't printing out the same
timestamps (like the comm tests).
- The above required yet another change to the writer API to
network_time to methods.
- Renamed ASCII logger "header" options to "meta".
- Fixes#763 "Escape # when first character in log file line".
All btests pass for me on Linux FC15. Will try MacOS next.
* topic/robin/log-threads: (42 commits)
Two more tweaks to reliably terminate when reading from trace.
This could be fixing the memory problems finally.
Fix compile errors due to now-explicit IPAddr ctors and global IPFamily enum.
Switching log buffer size back to normal
Teaching cmake to always link in tcmalloc if it finds it.
Extending queue statistics.
Small fixes and tweaks.
Don't assert during shutdown.
Reverting accidental commit.
Finetuning communication CPU usage.
Adding new leak tests involving remote logging.
Removing some no longer needed checks.
Fixing problem logging remotely when local logging was turned off.
Preventing busy looping when no threads have been spawned.
Prevent manager from busy looping.
Adding missing includes needed on FreeBSD.
Updating submodule(s).
Updating submodule(s).
A number of bugfixes for the recent threading updates.
Making exchange of addresses between threads thread-safe.
...
- Data queued at termination wasn't written out completely.
- Fixed some race conditions.
- Fixing IOSource integration.
- Fixing setting thread names on Linux.
- Fixing minor leaks.
All tests now pass for me on Linux in debug and non-debug compiles.
Remaining TODOs:
- Needs leak check.
- Test on MacOS and FreeBSD.
- More testing:
- High volume traffic.
- Different platforms.
This is based on Gilbert's code but I ended up refactoring it quite a
bit. That's why I didn't do a direct merge but started with a new
branch and copied things over to adapt. It looks quite a bit different
now as I tried to generalize things a bit more to also support the
Input Framework.
The larger changes code are:
- Moved all logging code into subdirectory src/logging/. Code
here is in namespace "logging".
- Moved all threading code into subdirectory src/threading/. Code
here is in namespace "threading".
- Introduced a central thread manager that tracks threads and is
in charge of termination and (eventually) statistics.
- Refactored logging independent threading code into base classes
BasicThread and MsgThread. The former encapsulates all the
pthread code with simple start/stop methods and provides a
single Run() method to override.
The latter is derived from BasicThread and adds bi-directional
message passing between main and child threads. The hope is that
the Input Framework can reuse this part quite directly.
- A log writer is now split into a general WriterFrontend
(LogEmissary in Gilbert's code) and a type-specific
WriterBackend. Specific writers are implemented by deriving from
the latter. (The plugin interface is almost unchanged compared
to the 2.0 version.).
Frontend and backend communicate via MsgThread's message
passing.
- MsgThread (and thus WriterBackend) has a Heartbeat() method that
a thread can override to execute code on a regular basis. It's
triggered roughly once a second by the main thread.
- Integration into "the rest of Bro". Threads can send messages to
the reporter and do debugging output; they are hooked into the
I/O loop for sending messages back; and there's a new debugging
stream "threading" that logs, well, threading activity.
This all seems to work for the most part, but it's not done yet.
TODO list:
- Not all tests pass yet. In particular, diffs for the external
tests seem to indicate some memory problem (no crashes, just an
occasional weird character).
- Only tested in --enable-debug mode.
- Only tested on Linux.
- Needs leak check.
- Each log write is currently a single inter-thread message. Bring
Gilbert's bulk writes back.
- Code needs further cleanup.
- Document the class API.
- Document the internal structure of the logging framework.
- Check for robustness: live traffic, aborting, signals, etc.
- Add thread statistics to profile.log (most of the code is there).
- Customize the OS-visible thread names on platforms that support it.
