Indexing delays

Incident Report for Mezmo Status Page

Postmortem

Thank you again for your continued patience during this major transition. We've been working diligently to not only resolve all issues, but continually improving our monitoring and tooling.

In order to manage capacity from outages from earlier in the week, we started additional message brokers to give us some spare capacity in case of incoming spike traffic. As it turns out, this inadvertently triggered a bad edge case in our load balancing logic which caused ingestion delays to slowly increase from 10 minutes to well over an hour. This left us scratching our heads, wondering how more capacity could slow things down.

The load balancing algorithm we used balances by number of processes, which roughly translates to CPU cores. With 5 brokers at 4 cores each, this creates a total of 20 messaging queues. Each queue requires a minimum of 1 worker to be assigned, otherwise no data would processed on that queue. Queues with heavier traffic are automatically assigned more worker processes.

When we increased the number of brokers from 5 to 10, the number of queues increased from 20 to 40. With the required minimum of 1 worker per queue, this increased the number of statically assigned workers, and reduced the total pool of remaining workers. Without as many available workers, the heavier queues were not able to receive the worker resources they needed to drain their queues, resulting in ingestion delays for both live tail and indexing.

While most of these message queues had little to no lag, a couple of queues had a lag of several hours. To temporarily reduce lag, we manually assigned workers to process the higher volume queues. After several hours of flushing, the handful of large queues finally emptied this morning around 5 AM PDT.

This triggered a bigger discussion on why the data was sent unevenly to the queues in the first place. We've come up with a number of different solutions that we'll be testing over the next week or so. In the meantime, we've put in some code that would natively remove certain queues from being loaded with new data until workers can process the data already there. This guards against any potentially bad algorithms we might be testing. A good circuit breaker that's been working well.

We've also continued in our monitoring and tooling improvements for our ingestion pipeline and will be working heavily in this area for the next few sprints. We've always had end-to-end testing but it was mainly for the status page and only tested latency of various public endpoints. Our new monitoring will not only test the load balanced endpoint but each of the backends that the load balancer points to.

Finally to our customers, thank you for your patience and support. We will continue to improve LogDNA for you.

  • The LogDNA Team
Posted Apr 07, 2018 - 07:37 UTC

Resolved

This incident has been resolved.
Posted Apr 06, 2018 - 12:10 UTC

Monitoring

Live tail should be fully caught up for all ingestion sources as of about 3 hours ago. All but 2 of our queues are caught up for indexing, which should be finished in about 4 hours. We've also made our statuspage job more reliable.
Posted Apr 06, 2018 - 10:20 UTC

Update

We're working through our backlog of messages. Some newly ingested data may arrive instantly, while others may be delayed, depending on load balancing to a fully up to date messaging broker vs one that's processing backlog. No ETA yet on being fully live. Will update again.
Posted Apr 05, 2018 - 07:12 UTC

Identified

We're currently experiencing indexing delays > 30 minutes. (This is different than Live Tail latency. Indexing is when a line that's inserted is available for search.)
Posted Apr 04, 2018 - 21:52 UTC