Traffic Logging data issue with Fortigate FG200E v5.6.6

[Frosty]

Just a note for others regarding FortiOS v5.6.6

We upgraded our FG200E on 2 OCT 2018 from v5.6.2 to v5.6.6 and since then some of the traffic logging data being recorded in our Fortianalyzer VM v5.6.5 seems to be going pear-shaped.

We only realised this today when we ran some traffic reports for October 2018 which report on our Internet link ... it went from showing an average of maybe 500GB/month (~20GB/day) to extremes like 14TB/day (completely technically impossible to achieve).

Am going to open a ticket with Fortinet today about it.

[Frosty]

So further to this issue, I still have a ticket open with Fortinet and we're investigating.

I found some very strange log data being produced.

When a client connects in to our network via Direct Access, it opens an IP-HTTPS tunnel to the Direct Access server and the traffic in/out of the network is transmitted through this connection.

Exactly every 2 mins, we see a new log entry, same SRCIP and DSTIP, but with a slowly incrementing Sent/Received value. 

There are dozens, if not hundreds of these logs entries, for each Direct Access client, but it is my belief that there is actually only one (1) connection and that the total amount of traffic over that connection would be accurately represented by only the latest log entry.  e.g. if the log entries start at 0MB and every 2 mins went 1MB, 2MB, 3MB, 4MB, then the amount of data transmitted is 4MB ... not 10MB.

My reasons for believing this is that the amount of Sent/Received data ALWAYS and ONLY ever increases from log entry to log entry; it NEVER decreases (for that combination of SRCIP and DSTIP).

I checked the Session ID of these incrementing log entries and, for each combination of SRCIP and DSTIP, the Session ID is the same.

Yet to be proven though whether this is a bug, or correct operation; I need to do some more diagnostics and I need to check back to September when we were running v5.6.2 to see whether the log data has the same pattern or looks different.

[Frosty]

So this was eventually confirmed as a Bug by Fortinet.

But I just noticed something in recent Release Notes for the Fortianalyzer which referred to "open sessions" having a LogID = 20 and that a "closed session" has a LogID = 13.  This set me wondering whether I could filter out all these buggy not-closed sessions from my Internet usage reporting in the Fortianalyzer (instead of just waiting for a patch from Fortinet, which might take months).

So I have added "and not logid_to_int(logid) = 20" to my dataset query WHERE clauses, like this:

where   $filter  and not logid_to_int(logid) = 20

Initial signs look good.  I have been able to run the query with this added bit in the Where clause and could exactly replicate my original non-buggy report data from back in August (before the Fortigate firmware was upgraded).  When I ran this on current, buggy data, the reporting looks pretty right to me.  The values reported for our Internet usage look plausible again.

This might be a "good enough" workaround until the updated Fortigate firmware comes out?

[Frosty]

Pedantic observation:  my use of a Function inside a Where clause is not optimal ... but as a quick-n-easy workaround, it is fine, and since my Fortianalyzer-VM runs on SSD storage, it runs just fine.