Hey everyone,
Thank you for your patience. The week started off pretty rough, but all reported issues have been fully resolved along with a few historically elusive bugs that were especially difficult to squash.
Over the past several months, we have been working on replacing the core components of our ingestion pipeline. This new pipeline was tested over the course of 3 months, slowly phasing over our own account, followed by select customer accounts. Last week, all customers were finally switched over to this new pipeline, with seemingly no issues.
However, around 10:30 AM PDT on Saturday, the speed at which we process log data began to slow. As a result, log lines entering from certain endpoints became delayed or even unable to enter our system. By 2 PM, traffic was diverted to our older pipeline and service was fully restored.
On Monday morning, we began a more thorough investigation, and attempted to recover any unprocessed log data cached on the new pipeline. We began the task of sorting through logs, customer inquiries, and machine metrics to pinpoint what went wrong over the weekend.
The new ingestion pipeline is a response to an increase in the size and variability of the traffic we receive. The nature of this traffic compounds the difficulty in investigating issues with the pipeline since we still need to process incoming traffic. One of our engineers pinpointed an issue with errantly large file offset lengths that slowed down our messaging queue. We also discovered a separate issue with our Heroku endpoint, completely unrelated to our new pipeline, which occurred during the same time as a result of peak traffic. While we quickly patched both of these issues, traffic had already started picking up on our old pipeline, resulting in increasing delays.
In order to switch traffic back onto our new pipeline, we had to spin up additional machines, remove the machines with recovery data out of rotation, and then switch traffic back onto the new pipeline. After doing so, live tail was restored instantly, and the old pipeline continued backfilling the delayed data. Once the backfill completed, we transferred the parsing workers over to the recovery section of our new pipeline, and attempted to process and recover as much data as possible from the weekend. While we were able to recover a good amount of data, we unfortunately were not able to recover all of it.
On Tuesday morning, we received several reports of missing lines sent from syslog clients. Initially, we identified a very slow memory leak with our syslog ingestion servers related to the new pipeline changes, but we later determined that this leak was unrelated to the reported issue. Nonetheless, we quickly patched the source of the memory leak.
Upon further investigation, not only were we unable to find any missing syslog lines, but we could not find any related alerts reported in the last 24 hours. We even tried to find commonalities between customers reporting issues, but to no avail. Finally, after systemtically stepping through the startup sequence of our syslog servers, we were able to pinpoint an issue with custom port bindings. During startup, the syslog server binds to the default syslog ports, as well as all custom provisioned ports. If a required port is not available for binding, the server will fail to bind to the socket and the resulting client connections are severed or hung depending on how the connecting syslog client interprets the event. So, even if the syslog client is restarted, unless the load-balanced DNS record returns a different server with the correct custom port binding, the client would be unable to establish the connection, resulting in lines never making it to the ingestion endpoint.
As it turned out, this issue had been occurring for some time, but very infrequently. Because the new pipeline required multiple restarts of our syslog ingestion servers, the port conflicts showed up far more often than usual. In addition, the new pipeline client present in the syslog server is also significantly faster than the old pipeline client, resulting in a higher likelihood of port conflicts, as a result of the socket bindings having less time to be destroyed. And, with different servers having issues with different ports on each restart, this issue was nearly impossible to reproduce.
To fix this, we implemented a fast retry mechanism to ensure that even if there is port binding conflict on startup, it can always attempt binding again. We also instrumented better logging and alerting, so we are notified of this issue in a timely manner. This was definitely an oversight on our part, but we are glad this longstanding bug has finally been squashed.
While we were dealing with syslog, customers on our free plan began reporting not being able to live tail their logs. However, our own account and all the paid accounts we checked had no issues accessing live tail. The lead engineer responsible for our new pipeline dug through his code, and found that the new pipeline misinterpreted a flag specific to accounts with no retention or no parsing as an excluded line, resulting in no live tail. Within a few minutes he pushed a fix, and live tail was immediately restored.
Throughout the troubleshooting process, our traffic continued to grow, so we also added more database resources to handle the increased volume of logs. This will safeguard against further growing pains as we scale.
Even though the initial switch to the new pipeline was a bumpy one, ultimately it provides a more reliable, performant, and scalable solution than our previous one (check out our super fast live tail times on the status page). In addition, we are excited for the new use cases this new pipeline supports, and will continue to retrofit our existing applications to interface with the new pipeline directly.
With our most risky pipeline transition behind us, we are continuing to add more and more monitoring and instrumentation to guard against issues like the ones above from affecting customers in the first place. We are optimistic that we will not only be able to improve our existing service, but also accelerate feature development as a result of having a newer, more extensible foundation.
Lastly, we want to thank all of our customers for reporting these issues in such a calm and detailed manner. This has helped us tremendously in being able to quickly and ruthlessly hunt down bugs. Your unwavering support during challenging times means the world to us.
Thank you.
- The LogDNA Team