More data:
I took Ben's PacketLossLogtailer.py script and striped out the Ganglia specific stuff. PacketLossAverager.py does exactly the same thing Ben's did, except reads from stdin and outputs to stdout.
I then took the current packet-loss.log file from locke, and split it into 1 file per run (about 1 file for every 10 minutes in the last 24 hours). I then ran PacketLossAverager.py on each file and output the results. I did this a few times, each time removing or only focusing on particular host groups (all hosts, only ssl hosts, only pmtpa squid hosts, etc.)
The most interesting numbers are these:
SSL hosts regularly report > 60% loss.
pmtpa squids hover around 0%, but with a larger and variable margin of error. This is probably due to the fact that they don't send as much traffic as the other hosts.
If I remove just SSL hosts from the calculation, average loss goes down to around 0%. If I remove both SSL hosts and tampa squids, average loss is again around 0%, with an error margin of ~0.5%
Erik Zachte took the sampled-1000 logs and computed the average distance between sequence numbers per month. I've loaded these into a Google Spreadsheet.
Since this is sampled-1000, a healthy monthly average sequence distance is about 1000. There are only a few errant notables.
Since November, the upload pmtpa squids (last column on the right) have an average distance of about 1200. That's 20% off of what it should be. More importantly, the SSL hosts in all clusters are way way off.
nginx (SSL) udp2log sequence numbers have never worked, but we are including them in our packet loss calculations anyway.
Here are the relevant ganglia links again:
As David said, we still have to figure out what happened in October. Whatever happened, notice that oxygen's packet loss average didn't jump up as high as the others did in October. oxygen does not receive logs from the nginx SSL servers, so its numbers aren't as skewed.
If we really want reliable packet loss numbers, we should do two things.
1. Remove nginx from packet-loss calculation.
Since the nginx SSL logs are proxy duplicates of real logs anyway, and oxygen is already not receiving them, I think we should just stop including them in the webrequest udp2log stream altogether. If we need information about SSL requests, we can start logging the X-Forwarded-Proto header. Or we can make nginx log to a different port, and keep those requests as their own logs.
2. Make PacketLossLogtailer.py smarter. Currently, the numbers emitted to ganglia do not account for traffic proportion or margin of error. PacketLossLogtailer.py looks at packet-loss.log (generated by packet-loss.cpp in the udplog repo), sums the percent loss for each distinct hostname, and then averages those. We could make this smarter by using the margin of error or the relative traffic proportion per host to weight the host's percent loss in the overall percent loss average.
Or, could we use the median percent loss instead of the average?
(Also, I still need to read packet-loss.cpp to make sure we understand how the error margin and percent loss per host is calculated in the first place…)
-Ao
Hey all, quick update with a summary of where we stand and the plan of attack.
tl;dr: It's probably the known-to-be-busted nginx sequence numbers on the SSL boxes polluting the average. We should modify PacketLossLogtailer.py to drop their entries.
1. Ganglia Numbers
As the Ganglia numbers are our main operational metric for data-integrity/analytics system health, it's essential we understand how they're generated.
A rough outline:
- The PacketLossLogtailer.py script aggregates the packet-loss.log and reports to Ganglia
- packet-loss.log, in turn, is generated by bin/packet-loss from the udplog project. From Andrew's previous email, lines look like (SPOILER ALERT):
[2013-03-20T21:38:47] ssl1 lost: (62.44131 +/- 4.19919)%
[2013-03-20T21:38:47] ssl1001 lost: (66.71974 +/- 0.20411)%
[2013-03-20T21:38:47] ssl1002 lost: (66.78863 +/- 0.19653)%
Andrew is digging into the source to ensure we understand how these error intervals are generated, especially given the logtailer drops entries with a high error margin.
We assume we won't find anything shocking in packet-loss.cpp, but we need to be sure we understand what these numbers mean.
2. Current Alerts
Erik Zachte performed analysis of sequence number deltas via the sampled 1:1000 squid logs, finding the SSL hosts had loss 60%+; Andrew verified this using the packet-loss logs. It's a known bug that nginx generates busted sequence numbers, so this is probably the explanation. Andrew is following up.
There's a clear trend visible if you look at the loss numbers over the last month -- the 90th shows it most clearly:
As Oxygen does not receive logging from the SSL proxies, this seems almost certain to be the answer.
However, while filtering out entries in the packet-loss log from the SSL hosts might fix the alerts, it doesn't explain why we're seeing the increase in the first place. More troubling, there was a huge increase in Oct that we somehow did not notice:
There are theories aplenty, with both load and filters contributing to the loss numbers. Further, different filters run on each box (themselves with a wide range of hardware), so their performance isn't perfectly comparable.
Andrew's on point looking into these questions, but the immediate next-step is to ignore the SSL machines in the packet-loss log. Modifying PacketLossLogtailer.py lets us preserve the data for future analysis.