FlowTracker creating initial graph, but not updating after that

[Kees Leune]

I am new to the FlowViewer toolset, and liking what I see so far. One of the issues that I ran into is that my FlowTrackers will list traffic flowing when they are initially created, but indicate that there is no traffic after that.

Note that the graphs are updating; it is just that they indicate that there is no traffic. My flow data is being received and stored by SiLK.

FlowTracker_Collector and FlowTracker_Grapher are running and I believe that they have sufficient file system privileges to write to where they need to write and read where they need to read.

How do I go about debugging this issue? I've been looking through the DEBUG_TRACKER* files in Flow_Working and manually executing the commands in DEBUG_TRACKER_C, and they appear to be working well well executed manually.

[Joe Loiacono]

Hi Kees,

If you've made any configuration changes in FlowViewer_Configuration.pm, then you'll need to restart FlowTracker_Collector and FlowTracker_Grapher.

"my FlowTrackers will list traffic flowing when they are initially created"

Can you explain this a little more. Are you doing a 're-create' where you adjust the start time to an earlier time, and then seeing vaild data for the time period from the start to the time you submitted the FlowTracker form, but zero after that?

Your debugging approach is spot on.

From DEBUG_TRACKER_C, are you seeing a zero update value (epoch_time:value), like below:

from: start flow_BUCKETS to: end flow_BUCKETS elapsed seconds: 0.000200 running: 522007.053627
from: end flow_BUCKETS to: start RRDtool_update elapsed seconds: 0.001647 running: 522007.055274
ASTER to GSFC After 1411677000:0

We'll get this solved ...

Joe

[Kees Leune]

I have been adding more debug statements to the code, and I'm almost positive that there is a timezone mismatch. SiLK records in UTC, while the Collector does not like that. This is further evidenced by looking at the output in DEBUG_TRACKER_C (with my additions):

$ cat Flow_Working/DEBUG_TRACKER_C 
from: end this_filter                to: start next_filter               elapsed seconds: 300.002888  running: 1200.084101

Existing filter: /data/FlowTracker_Files/FlowTracker_Filters/resnet_flows.fil
from: start next_filter              to: start SiLK_processing           elapsed seconds: 0.000458  running: 1200.084559
rwfilter_command: /opt/SiLK/bin/rwfilter --data-rootdir=/data/flows --class=all --type=all --sensors=Resnet --start-date=2014/09/26:09 --end-date=2014/09/26:11 --active=2014/09/26:11:05:00-2014/09/26:11:10:00  --pass=/opt/FlowViewer_4.4/Flow_Working/FlowTracker_Prefiltered_Resnet_allallResnet
Partitioning switches:  --scidr=10.73.0.0/16
silk_command: /opt/SiLK/bin/rwfilter  --scidr=10.73.0.0/16 --pass=stdout /opt/FlowViewer_4.4/Flow_Working/FlowTracker_Prefiltered_Resnet_allallResnet | /opt/SiLK/bin/rwcount --bin-size=300 --start-time=2014/09/26:11:05:00 --end-time=2014/09/26:11:10:00 --epoch-slots --no-titles > /opt/FlowViewer_4.4/Flow_Working/FlowTracker_Collector_output
from: start SiLK_processing          to: end SiLK_processing             elapsed seconds: 0.010715  running: 1200.095274
from: end SiLK_processing            to: start SiLK_BINS                 elapsed seconds: 0.000069  running: 1200.095343
Skipping data: bucket_start=1411729500 epoch_start=1411743900 epoch_end=1411744200
Skipping data: bucket_start=1411729800 epoch_start=1411743900 epoch_end=1411744200
from: start SiLK_BINS                to: end SiLK_BINS                   elapsed seconds: 0.000139  running: 1200.095482
from: end SiLK_BINS                  to: start RRDtool_update            elapsed seconds: 0.000045  running: 1200.095527
Resnet Flows  1411744200:0
Executing rrdtool_command: /usr/bin/rrdtool update /data/FlowTracker_Files/FlowTracker_RRDtool/resnet_flows.rrd 1411744200:0
from: start RRDtool_update           to: end RRDtool_update              elapsed seconds: 0.005278  running: 1200.100805
from: end RRDtool_update             to: end this_filter                 elapsed seconds: 0.000111  running: 1200.100916

Note the lines starting with "Skipping data". Bucket_start is 14400 seconds prior to epoch_start. Not coincidentally, I am four hours behind UTC.

I've tried editing the $time_zone variable in FlowViewer_Configuration.pm to be either blank, or UTC, but to no avail.

Can you explain this a little more. Are you doing a 're-create' where you adjust the start time to an earlier time, and then seeing vaild data for the time period from the start to the time you submitted the FlowTracker form, but zero after that?

Correct.

-Kees

[Joe Loiacono]

Yes - great work. Ironically I was doing almost the exact debug in FlowGrapher_Main.cgi for user Isaque Profeta when I saw your latest post.

So, the quick response is to get start_epoch and end_epoch into the same time-zone as the data. I will be working on this making sure it doesn't adversely affect some other use of those variables.

The $timezone variable in FlowViewer_Configuration.pm has heretofore been used for display purposes only. Perhaps we could use that to set up the conversion; or make a system call to get the timezone.

The several installs I work on are all system time = UTC as well as device exports and this complicates testing for me so I greatly appreciate your work on this and look forward to getting it straightened out for everyone.

SiLK Installation documentation has this:

2.3.11 Using your local timezone

By default, SiLK uses UTC when printing timestamps to the user, and it expects timestamps from the user to be in UTC. Giving configure the --enable-localtime switch will modify SiLK to print and expect times in the local timezone. (Data files are always indexed by UTC.)

Did you use the --enable-localtime switch when you built?

Thanks,

Joe

[Kees Leune]

Did you use the --enable-localtime switch when you built?

Short answer: no. config.log in the SiLK source tree confirms that:

This file contains any messages produced by compilers while
running configure, to aid debugging if configure makes a mistake.

It was created by SiLK configure 3.8.3, which was
generated by GNU Autoconf 2.69. Invocation command line was

$ ./configure --prefix=/opt/SiLK --enable-ipv6 --enable-data-rootdir=/data/flows

I look forward to seeing a possible fix. Having not too much experience with Perl and with timezone conversion, doing this myself may take a while :-) I'll give it a shot when I have some overhead though.

[Joe Loiacono]

No problem. I'll create the fix. I'll send you an updated FlowTracker_Collector. Very soon is my plan.

[Joe Loiacono]

Kees -

I sent you a couple of mods to correct the situation.

I'll be working up a general fix for the next distribution, version 4.5.