Mirror/zeek
1
0
Fork 0
mirror of https://github.com/zeek/zeek.git synced 2025-10-02 06:38:20 +00:00
Code Issues Projects Releases Packages Wiki Activity Actions 1

GH-443: fix uses of timestamp 0 in cluster diagnostic logs

Browse source 
For broker.log and cluster.log: there was a race condition.  A worker's
first IOSource that it processes is potentially Broker if there were
no packets available yet and thread scheduling happens to work out
such that network connections (inside CAF threads) become established
before we enter the main I/O loop.  Such peering establishments would
generate logs with timestamp 0 as there was not yet any code path
taken that would update network_time.

For reporter.log: any non-worker (packet-processing) node would just
unnecessarily use a timestamp of 0 for their reporter messages.
This commit is contained in:
Jon Siwek 2019-06-27 23:00:42 -07:00
parent 7b56925b77
commit 430f9a92c6
4 changed files with 15 additions and 9 deletions
Download patch file Download diff file Expand all files Collapse all files

2
src/Reporter.cc
View file

@ -491,7 +491,7 @@ void Reporter::DoLog(const char* prefix, EventHandlerPtr event, FILE* out,
val_list vl(vl_size);
if ( time )
vl.append(new Val((bro_start_network_time != 0.0) ? network_time : 0, TYPE_TIME));
vl.append(new Val(network_time ? network_time : current_time(), TYPE_TIME));
vl.append(new StringVal(buffer));

6
src/broker/Manager.cc
View file

@ -941,6 +941,12 @@ void Manager::Process()
if ( had_input )
{
if ( network_time == 0 )
// If we're getting Broker messages, but still haven't initialized
// network_time, may as well do so now because otherwise the
// broker/cluster logs will end up using timestamp 0.
net_update_time(current_time());
++times_processed_without_idle;
// The max number of Process calls allowed to happen in a row without

12
testing/btest/Baseline/core.reporter/logger-test.log
View file

@ -1,6 +1,6 @@
reporter_info|init test-info|/Users/jsiwek/Projects/bro/bro/testing/btest/.tmp/core.reporter/reporter.zeek, line 8|0.000000
reporter_warning|init test-warning|/Users/jsiwek/Projects/bro/bro/testing/btest/.tmp/core.reporter/reporter.zeek, line 9|0.000000
reporter_error|init test-error|/Users/jsiwek/Projects/bro/bro/testing/btest/.tmp/core.reporter/reporter.zeek, line 10|0.000000
reporter_info|done test-info|/Users/jsiwek/Projects/bro/bro/testing/btest/.tmp/core.reporter/reporter.zeek, line 15|0.000000
reporter_warning|done test-warning|/Users/jsiwek/Projects/bro/bro/testing/btest/.tmp/core.reporter/reporter.zeek, line 16|0.000000
reporter_error|done test-error|/Users/jsiwek/Projects/bro/bro/testing/btest/.tmp/core.reporter/reporter.zeek, line 17|0.000000
reporter_info|init test-info|/home/jon/pro/zeek/zeek/testing/btest/.tmp/core.reporter/reporter.zeek, line 8|1561700937.882616
reporter_warning|init test-warning|/home/jon/pro/zeek/zeek/testing/btest/.tmp/core.reporter/reporter.zeek, line 9|1561700937.882616
reporter_error|init test-error|/home/jon/pro/zeek/zeek/testing/btest/.tmp/core.reporter/reporter.zeek, line 10|1561700937.882616
reporter_info|done test-info|/home/jon/pro/zeek/zeek/testing/btest/.tmp/core.reporter/reporter.zeek, line 15|1561700937.882616
reporter_warning|done test-warning|/home/jon/pro/zeek/zeek/testing/btest/.tmp/core.reporter/reporter.zeek, line 16|1561700937.882616
reporter_error|done test-error|/home/jon/pro/zeek/zeek/testing/btest/.tmp/core.reporter/reporter.zeek, line 17|1561700937.882616

4
testing/btest/core/reporter.zeek
View file

@ -1,7 +1,7 @@
#
# @TEST-EXEC: zeek %INPUT >output 2>&1
# @TEST-EXEC: zeek -b %INPUT >output 2>&1
# @TEST-EXEC: TEST_DIFF_CANONIFIER=$SCRIPTS/diff-remove-abspath btest-diff output
# @TEST-EXEC: TEST_DIFF_CANONIFIER=$SCRIPTS/diff-remove-abspath btest-diff logger-test.log
# @TEST-EXEC: TEST_DIFF_CANONIFIER="$SCRIPTS/diff-remove-abspath | $SCRIPTS/diff-remove-timestamps" btest-diff logger-test.log
event zeek_init()
{