Now it should work. However - this commit changes a basic assumption
of the threading queue. This basic assumption is, that nothing can
be read out of the out-queue of a dead thread. I think that reading
out of the queue of a dead thread makes perfect sense (when the thread
shuts down, pushes the rest of its work on the queue and says bye,
and wants the main thread to pick it up afterwards) - however, I
guess one can be of a differing opinion here.
In any case, it makes stuff a bit easier to understand - in my opinion.
It took me a while to find out why the messages disappear in thin
air and never arrive in the main thread ;)
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)
PrepareStop() is now SignalStop() and just signals a thread that it
should terminate. After that's called, WaitForStop() (formerly Stop())
wait for it to actually finish processing.
When stopping writers during operation, we now no longer wait for them
to finish.
failure.
Once a writer/reader Do* method has returned false, no further ones
will be executed anymore. This is primarily a safety mechanism to make
it easier for writer/reader authors as otherwise they would often need
to track the failure state themselves (because with the now delayed
termination from the earlier commit, furhter messages can now still
arrive for a little bit).
If a thread command fails (like the input framework not finding a
file), that now (1) no longer hangs Bro, and (2) even allows for
propagating error messages back before the thread is stops.
(Actually, the thread doesn't really "stop"; the thread manager keeps
threads around independent of their success; but it no longer polls
them for input.)
Closes#858.
* 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.
...
Threads will now reliably get a call to DoFinish() no matter how the
thread terminates. This will always be called from within the thread,
whereas the destructor is called from the main thread after the child
thread has already terminated.
Also removing debugging code.
However, two problems remain with the ASCII writer (seeing them only
on MacOS):
- the #start/#end timestamps contain only dummy values right now.
The odd thing is that once I enable strftime() to print actual
timestamps, I get crashes (even though strftime() is supposed to
be thread-safe).
- occassionally, there's still output missing in tests. In those
cases, the file descriptor apparently goes bad: a write() will
suddently return EBADF for reasons I don't understand yet.
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.
(because it could hang later still).
Also logging to stderr as well to make sure one sees it.
Also adding code to the ASCII writer to catch termination
inconsistencies.
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.
* origin/topic/robin/dataseries:
Moving trace for rotation test into traces directory.
Fixing a rotation race condition at termination.
Portability fixes.
Extending DS docs with some examples.
Updating doc.
Fixing pack_scale and time-as-int.
Adding format specifier to DS spec to print out double as %.6f.
DataSeries updates and fixes.
DataSeries tuning.
Tweaking DataSeries support.
Extending log post-processor call to include the name of the writer.
Removing an unnecessary const cast.
DataSeries TODO list with open issues/questions.
Starting DataSeries HowTo.
Additional test output canonification for ds2txt's timestamps.
In threads, an internal error now immediately aborts.
DataSeries cleanup.
Working on DataSeries support.
Merging in DataSeries support from topic/gilbert/logging.
Fixing threads' DoFinish() method.
But: there are still a few places where I am sure that there are race conditions & memory leaks & I do not really like the current interface & I have to add a few more messages between the front and backend.
But - it works :)
- 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.
