The error on the first change of the day is almost never bad luck

An error that happens "now and then, on the first change of the day" is almost never bad luck. It is usually a connection that fell asleep, a cache that kept something no longer valid or a clock nobody remembers. And it can be proven before it is fixed.

Imagine an ordinary morning at an online store. The person who looks after the catalog arrives, opens the system and makes the first change of the day: they correct a product's description and save it. Everything looks normal. Half an hour later, someone from sales writes in, worried: that product appears in the store's search with no price and no stock. Or worse, it no longer appears at all.

Nobody touched the price. Nobody deleted anything. The catalog person opens the product again and saves it without changing anything. The product comes back complete. It gets written down as "a glitch" and the day goes on. The next time it happens, days or weeks later, someone "fixes it by hand" again.

In the case we tell here, the people who lived with it estimate that they put up with that failure for a long time. When someone finally counted it, in testing, it showed up several times in a single month. And it always had the same shape: a single product, the first one edited that day.

This article is for whoever leads operations or technology, and for the team that maintains the systems. It covers four things:

1. What was really happening.
2. Why these errors survive for years.
3. How it is proven and fixed: reproduce the failure on purpose, fix the cause, stop a failure from writing broken data and validate by comparing the old against the new.
4. What to ask at your next committee and where to start this week.

What was really happening

An online store's search almost never reads directly from the database where the catalog lives. It reads from a search index: a copy of the catalog organized to find things fast. Between the two there is a process that copies each change. It can be built, for example, with MariaDB as the database, Logstash as the process that copies and Elasticsearch as the index. That process works all day: every minute it asks "what changed?" and takes the changes to the index.

To build each product, the process has to make a second query to the database: fetch its variants, that is, the versions of a single product, each with its own price and stock. To avoid opening a new connection every time, it keeps one open and reuses it.

The problem starts at night. Nobody edits products, so that connection sits still for many hours. And the database, by design, closes connections that have gone a long time without activity. In MariaDB and MySQL, for connections from programs (not those of a person at a console), that time is called wait_timeout and, if nobody changes it, it is 28,800 seconds: eight hours [1][2]. The MySQL manual says it plainly: by default, the server closes the connection after eight hours if nothing has happened [3].

The database closes its side, but the process does not find out. It keeps holding the connection as if it were alive. The next morning the first change arrives, the process uses that dead connection and the variants query fails. The database client only discovers that the connection no longer exists when it tries to use it [3]. In Java, with the MySQL driver (the piece of software that talks to the database on the program's behalf), the same event shows up as "Communications link failure". The driver itself suggests the cause: an idle time longer than the server's wait_timeout [4].

Up to this point it would be an error you retry and move on. What makes it expensive is what happens next.

The failure that writes over the good data

When the variants query fails, a filter like Logstash's jdbc_streaming does not stop the product. It adds an error tag to it and puts the default value in the variants field. If nobody configured that value, the field is left as a list with a single empty element: the product ends up with no variant data. And the filter lets it continue on its way [7]. The filter's code shows it clearly; the documentation only mentions it in passing, when describing the cache (cache_expiration) [5].

The product, now without variants, reaches the search index. And the index stores it under the same identifier the good product already had. That detail, normally a virtue, is the damage here. With the usual save action (index) on an ordinary index, storing a document with an identifier that already exists updates the whole document and increments its version [15][16]. You are not left with a broken product next to the good one; you are left with the broken one in place of the good one.

In the case, the second change of the day no longer failed: most likely, after the error, the dead connection was discarded and another one was opened. That depends on the driver and the connection manager, not on the filter; it is worth confirming in the log. That is why the next edit "fixed it" and the error only hit the first one.

Three usual suspects: a connection, a cache or a clock

The case has proper names, but the pattern does not. When an error appears "now and then" and almost always at the same time of day, or after a weekend, it is worth looking for something that has a timer.

A sleeping connection. The cut can come from three places, and the client only finds out when it uses the connection again:

• The database, as in this case: eight hours by default in MariaDB and MySQL [1][2].
• The network. In Amazon Web Services (AWS), for example, a private network's gateway to the internet (NAT Gateway) treats a connection as expired after 350 seconds or more without activity. Anyone who tries to keep using it gets a TCP reset packet (RST), which cuts the connection [11]. The AWS network load balancer, which spreads connections across several servers, also cuts at 350 seconds by default. For TCP connections that value can be configured between 60 and 6,000 seconds [12]. A firewall, the device that filters traffic between two networks, can do the same without warning anyone. The SANS Internet Storm Center documented such a case in 2007: a firewall deleted sessions after one hour of no use between an application server and an Oracle database [13].
• The operating system. The mechanism that keeps connections alive (TCP keepalive) depends on the operating system and on how each connection was opened. In the SANS case it started at two hours, too late for the firewall [13].

A cache. A cache is short-term memory: it keeps an answer so it does not have to ask for it again. If it keeps an empty or wrong answer, it repeats it until it expires. A filter like jdbc_streaming, for example, with its cache turned on (it comes that way by default), can do it. Faced with a transient error, it keeps the empty result for those parameters until its time runs out, five seconds by default [5][7].

A clock. Many copy processes decide what to read using a time: "bring me what changed after the last time". That time is called a watermark [6], and it has a trap we will see below: it does not always say what you think it does.

Why these errors survive for years

A director may reasonably ask how an error everyone has seen can last so long. The answer is almost never negligence. It is that this kind of error has four traits that protect it:

• It fixes itself. The next edit leaves the product right. An error that corrects itself destroys its own evidence: by the time someone from technology comes to look, there is nothing left to see.
• Nobody reproduces it. To see it you have to wait a whole night without activity and make a change right after. Nobody does that on a normal working day. So the error never shows up when someone is looking for it.
• It is repaired by hand and forgotten. Saving the product again takes a minute. Without a report there is no count, and without a count there is no priority.
• The symptom appears far from the cause. The person who sees the problem is in sales, in the search. The cause is in a timing agreement between two machines that nobody had written down. Sales does not know that connection exists, and whoever configured it does not see the search.

How it is proven and fixed

The temptation, when someone finally suspects the cause, is to change the configuration and wait. If the error stops appearing, it is considered solved. The problem is that "it stopped appearing" is exactly what was already happening between one failure and the next. An intermittent failure is proven before it is fixed. These are the four steps we follow.

1. Reproduce it on purpose

If the failure depends on a clock, you shorten the clock. In a test environment, the team lowers the database's wait_timeout to, say, 60 seconds. There is a detail many people miss: each connection takes that value at the moment it is opened [1][2]. Lowering the global value does not affect connections that already exist. That is why the practical thing is to restart the copy process, so that its connection is born with the short value.

Then you wait a couple of minutes, edit a product and look. The filter's error tag appears in the process log; in the index, the product without variants. A test of minutes replaces a wait of eight hours.

The test that convinces everyone is the real-time one. In a controlled test, after more than 10 hours without activity, the first edit failed and the next one went through fine. It was the exact symptom the business was seeing, triggered on purpose and with a timestamp.

2. Fix the cause, not the symptom

There are three standard answers to a connection that falls asleep, and they are the same in almost any technology: validate it before using it, renew it before it expires or keep it awake with periodic traffic.

In a filter like Logstash's jdbc_streaming, for example, the first one is an option: jdbc_validate_connection, which comes turned off by default [5]. When you turn it on, the process checks the connection before using it. If it is dead, it discards it and opens another [8][9].

Here is the nuance almost nobody reads. The option that goes with it, jdbc_validation_timeout, is documented as "how often to validate" and is 3,600 seconds by default [5]. In reality it works differently: the library that manages the connections only checks the ones that have gone longer than that time without being used [9]. A connection that spent the night idle has been inactive for much more than an hour. So with the default value it does get checked, and the database's eight-hour cut is covered.

But the cut can come from the network and be shorter, like the 350 seconds of a load balancer or a NAT. There, a connection idle for ten minutes would not be checked and would arrive dead. Against that cut you need another measure: lower that threshold below the cut, or keep the connection alive with traffic more frequent than the cut [11].

In Java, the principle is the same. HikariCP, a widely used connection manager, recommends that a connection's maximum lifetime be a few seconds shorter than any limit of the database or the infrastructure. It also offers to keep them alive with a periodic check [10]. And the MySQL driver for Java advises against its automatic reconnection option [4]: reconnecting blindly is not the official answer.

3. Stop a failure from writing broken data

Fixing the connection prevents the error every morning. It does not prevent the next error nobody has imagined. That is why the second change matters as much as the first: if part of the product could not be fetched, nothing is written.

With Logstash, for example, this is achieved with a condition after the filter. If the product carries the query's error tag (_jdbcstreamingfailure), it is discarded and does not reach the index [7]. The previous product, complete, stays where it was.

Two cases that look alike need to be told apart. The product that failed carries two tags: the error one and the "default value was used" one (_jdbcstreamingdefaultsused) [7]. A product that truly has no variants carries only the second. That is why the condition looks only at the error tag: the product without variants keeps being copied, on purpose, and only the one that failed when querying them is stopped.

This decision has a cost, and it should be said. If the query only asks for what comes after the watermark and the watermark has already moved forward, the discarded change is not recovered on its own. That is how it worked in the case; in your system, confirm it with the actual query. The product keeps its previous version until someone edits it again or the index is reloaded. For a director, the rule is clear without code: better yesterday's price than no price. A product with yesterday's data sells; one without a price disappears.

The underlying lesson, for the technical team: using the product's identifier as the identifier in the index makes repeating a load harmless, because the end result is the same [15]. That same property is what does the damage when the document arrives incomplete. A load that can be repeated without harm is not thereby safe: it also needs to not write when something is missing.

4. Check the clock and validate against the old

The copy process decides what to copy with a watermark: "bring me what changed after the last time I saw" [6].

The trap is that the time stored as "last modified" is not always the time the change was saved. Two terms help. A statement is an instruction given to the database, such as "change this price". A transaction is a bundle of statements that is saved all together or not at all; committing it is the moment its change is saved and others can see it.

In MySQL, NOW() returns the time the statement started, not the time it was committed [14]. Suppose the last-modified column is filled with NOW(), and that a large change takes a while to save: it starts at 10:00 and commits at 10:03. Its rows say "10:00". Meanwhile, the copy process has already read newer changes and moved its watermark past that. When the large change finally commits, its rows carry a time earlier than the watermark, and the next read no longer asks for them. They are lost silently. This risk belongs to the same family of limits that the Debezium team points out about change capture by periodic query: it can miss intermediate changes and does not see deletes [17].

There are two ways to close that door:

• A time margin. "I only read what is at least one minute old." The watermark no longer advances over seconds that can still receive changes. It reduces the risk, but it is not a guarantee: a transaction that takes more than a minute to commit can still be lost.
• Reading the database's log instead of a column with a time. This is called log-based change data capture (CDC). One example is Debezium reading the binary log of MariaDB or MySQL. That log stores operations in the order in which they were committed, deletes included [17][18]. Properly configured, it closes this particular window, in exchange for more pieces to configure and operate.

In the case we tell, the one-minute margin was chosen, with its limit written down.

The question every director should ask remains: how do we know the fix did not break anything that used to work? The answer in this case was a full comparison. The old query and the new one were run over the entire catalog, in testing, and gave exactly the same result. The new query only changed when it reads. Any difference would have been a new error. There was none.

And afterwards, the night test again. In a controlled test, after more than 16 hours without activity, the first edit went through without error: the exact case that used to fail. In addition, the products that had been left broken were repaired, and at the close of the review there were none left broken in testing.

Five questions for your next committee

1. Which errors "fix themselves" in our systems? Ask sales, customer service and whoever runs the catalog, not just technology. The best clues are usually with whoever repairs things by hand.
2. Does any of them always happen at the same time, on Monday, or after a night without use? If the answer is yes, there is a clock behind it.
3. Do we know how long each connection between our systems holds without use, and who cuts it first: the database, the network or the cloud? If nobody has it written down, nobody has decided it.
4. When a process cannot fetch all the information, what does it do? Does it leave what was there or publish something half-done?
5. When technology says "it's done", how did they prove it? Did they trigger the failure before the fix and trigger it again after, or did they just stop seeing it?

If two or more answers are "I don't know", the problem is not luck: measurement is missing.

Where to start this week

You do not need a project. You need a list. Ask the areas that operate your systems to write down, for two weeks, every time something "fixed itself" or "was repaired by hand": what it was, at what time and what was done. At the end of the two weeks, sort the list by time. If several entries cluster first thing in the morning or after a weekend, you already have your first suspect. One afternoon is enough for your technical team to start reproducing it in a test environment.

What Hábil does

When a failure repeats, Hábil's SWAT Team looks for the root cause, not another restart: it reproduces it, fixes it and gives you evidence of how it was verified, so that you can review it.

The first conversation is at no cost: its goal is to help you pinpoint which failure repeats, since when and how it can be proven. Write to us on WhatsApp.