Is Stream DNS Reporting Sessions Backwards?

[joeldavideng]

Has anyone else found that their Stream DNS records report sessions backwards? I did some pretty extensive testing today with my SysAdmins and my Stream logs appear to show the initial DNS request from my workstation to the Domain Controller as the last event and the Domain Controller to the authoritative name server as the first event. The entire transaction makes sense if you reverse it, but the time stamps definitely show one event occurred 100ms before the other.

I was thinking this may be an odd side effect of the way Stream collects DNS requests, but I'd like someone more knowledgable about the product to verify that assumption.

[joeldavideng · Accepted solution]

As it turns out, the answer is yes, Stream does in fact report DNS query events backwards. Each DNS record comes with two times; "timestamp", the start of the DNS session and "endtime", the end of the session. The default props.conf sets _time to "endtime", which produces the appearance of the backwards DNS events.

For example, if a workstation makes a DNS request through an internal DNS server who then passes the request to an external server you would expect to see

1. Workstation => Internal DNS
2. Internal DNS => External DNS
3. Internal DNS => External Authoritative DNS

However, since the workstation technically has the longest time to wait for its session to complete it will appear as
1. Internal DNS => External Authoritative DNS
2. Internal DNS => External DNS
3. Workstation => Internal DNS