Lab: Fail a Database Over and Time the Gap

This is a lab in the Solutions Architect Associate hands-on track. The full lab is in lab-saa-03-failover-timing.zip.

If this is your first lab, do the one-time, once-per-account setup: run the zip’s preflight.sh to confirm your account is ready, then deploy the lab reaper, a standing backstop that auto-deletes any lab you forget to tear down after 24 hours. This one creates a Multi-AZ RDS instance and an EC2 writer, both of which bill for as long as they exist, so tear down when you are finished.

The scenario

AWS publishes a number for Multi-AZ failover. For a Multi-AZ DB instance deployment it is typically 60 to 120 seconds. For a Multi-AZ DB cluster, the deployment with two readable standbys, it is typically under 35 seconds. Those are the numbers that end up in design documents and capacity plans.

The same documentation, in its list of operational guidelines, says to test failover yourself to understand how long the process takes for your particular use case, and to check that your application reconnects on its own afterwards. That instruction exists because the published number measures what RDS does. Between RDS finishing and your users being served again sit the DNS record, the client’s resolver, the TCP socket the application already had open, and whatever the application does with a query that comes back as an error.

In this lab a writer inserts one row a second. You reboot the primary with failover, then compare what the RDS event log says against what the writer’s own log says. Then you fix the writer and run it again.

What you’re given

CloudFormation builds a VPC with two private subnets in different Availability Zones, an RDS for PostgreSQL db.t4g.micro with MultiAZ: true across them, and a t4g.micro EC2 writer in a public subnet with an outbound-only security group. The instance profile carries AmazonSSMManagedInstanceCore so you can open a session on the writer when its user data misbehaves. A production writer belongs in a private subnet, reaching Secrets Manager and CloudWatch Logs through interface endpoints; the public subnet here is a debugging convenience and nothing more. The writer sits in one Availability Zone on purpose. It is measuring the database’s failure domain, and giving it a second zone would only add a second copy of the same client bug.

The DB instance is created with ManageMasterUserPassword: true, so RDS creates and owns the master secret. The writer reads it once at startup, creates a beats table, and then runs its loop. Every attempt appends one JSON line to a CloudWatch Logs stream, whether it succeeded or not:

{"seq": 1841, "t": 1806732845.113, "ok": true, "ms": 3.9}
{"seq": 1842, "t": 1806732846.114, "ok": false, "ms": 30014.2, "err": "InterfaceError"}

The loop keeps its cadence against a monotonic deadline rather than sleeping a flat second, so one slow attempt does not shift every attempt after it. That matters for the measurement: the gap you are after is the interval between the last ok before the failover and the first ok after it, and a drifting clock would blur both ends.

The gap in the code is the connection handling. As shipped, writer.py opens one connection at startup and does this with it:

def connect():
    return pg8000.native.Connection(
        user=CREDS["username"], password=CREDS["password"],
        host=ENDPOINT, port=5432, database="labdb", ssl_context=SSL)

def write_once(conn):
    if conn is None:
        time.sleep(30)          # TODO: back off politely so we do not hammer it
        conn = connect()
    conn.run("INSERT INTO beats (seq, at) VALUES (:s, now())", s=SEQ)
    return conn

Nothing in that is unusual. It reconnects after a failure, it avoids reconnecting in a tight loop, and it reads the endpoint hostname from the environment rather than an address. It is also the version that measures 214 seconds.

Your task

Rewrite connect and write_once so the writer recovers as fast as the database does. Three changes:

def connect():
    return pg8000.native.Connection(
        user=CREDS["username"], password=CREDS["password"],
        host=ENDPOINT, port=5432, database="labdb", ssl_context=SSL,
        timeout=5)

def write_once(conn):
    if conn is None:
        conn = connect()
    conn.run("INSERT INTO beats (seq, at) VALUES (:s, now())", s=SEQ)
    return conn

and, in the loop that calls it, close the connection before discarding it rather than dropping the reference and leaving the socket open:

    except Exception as e:
        log(seq, ok=False, err=type(e).__name__)
        try:
            conn.close()
        except Exception:
            pass
        conn = None

timeout=5. pg8000 defaults this to None, which leaves the socket with no deadline at all. The insert that is in flight when RDS interrupts the primary does not come back with an error; it sits in a blocking read while the kernel retransmits. Linux retransmits an established connection tcp_retries2 times before giving up, and the default of 15 works out to roughly a quarter of an hour. Five seconds is longer than any insert in this lab and far shorter than the failover, which puts the ceiling where you want it.

Close the connection, don’t just drop it. The shipped loop sets conn = None and leaves the old object to the garbage collector, which holds a socket open against a host that is no longer the primary. Closing it releases the socket where the error is logged. Rebuilding rather than reusing is what sends the client back through the resolver to find where the endpoint points now, because the standby that got promoted is a different host on a different address.

Drop the backoff. Thirty seconds of politeness against an outage of sixty to a hundred and twenty is a coin toss that adds half a minute to the gap when it loses. The database is not under load during a failover; it is absent. Retrying on the writer’s existing one-second cadence adds nothing to the promoted instance’s load and removes the whole term.

TCP keepalives do not appear in the fix because pg8000 turns them on by default. They also would not help here: tcp_keepalive_time on Linux defaults to 7200 seconds, so keepalives detect a dead peer on an idle connection in two hours. The socket deadline is what does the work on a connection that is busy.

Run it

./scripts/deploy.sh          # VPC, Multi-AZ instance, writer; ~15 minutes
./scripts/failover.sh        # reboot with failover, wait for RDS-EVENT-0049
./scripts/measure.py         # print both intervals
./scripts/teardown.sh

Give deploy.sh about fifteen minutes the first time, because a Multi-AZ instance provisions two of everything. On later runs it re-uploads writer.py and restarts the systemd unit without touching the stack, which takes seconds. Let the writer run for a couple of minutes before you fail anything over, so there is a clean baseline to measure against.

failover.sh calls reboot-db-instance --force-failover, which is the documented way to simulate an instance failure. The DB instance has to be in the available state and configured for Multi-AZ, or the call is rejected. The script then polls describe-events until RDS-EVENT-0049 lands.

A reboot with failover is a cooperative failure. RDS interrupts the database abruptly, but the host is still there and the socket usually gets torn down rather than going silent, so the numbers here sit at the optimistic end. A zone that stops answering produces no teardown at all, which is where the socket deadline stops looking like belt and braces.

measure.py pulls the two series and lines them up:

RDS event log
  09:41:12  RDS-EVENT-0013  Multi-AZ instance failover started.
  09:42:08  RDS-EVENT-0015  Multi-AZ failover to standby complete - DNS
                            propagation may take a few minutes.
  09:42:21  RDS-EVENT-0049  Multi-AZ instance failover completed.
  RDS-side interval: 69s

Writer
  last ok before   09:41:14  seq 1841
  first ok after   09:44:48  seq 2055
  failed attempts  8   longest single attempt 62.4s
  application gap  214s

The application was down 3.1x longer than RDS was.

Then apply your change, run deploy.sh again to push the new writer.py, wait for a fresh baseline, and fail it over a second time. The gap should land in the eighties, within twenty seconds or so of the RDS interval.

Run it a third time before you believe any of it. The RDS-side interval moves around with database activity and crash recovery, and the writer’s gap moves around with where in the cadence the failover happens to fall. One measurement is an anecdote.

If it fails

• No log stream at all. The writer never got as far as its loop. Open a session on the instance and read /var/log/cloud-init-output.log. The usual causes are the instance profile missing secretsmanager:GetSecretValue on the RDS-managed secret, or the database security group not admitting the writer’s group on 5432.
• measure.py says no failover events found. describe-events defaults to the last hour and takes --duration in minutes; the script passes 30. If the reboot was rejected rather than run, failover.sh prints the error and the event log stays empty. Check that the instance is Multi-AZ, and that it is available rather than backing-up or modifying.
• RDS-EVENT-0034, abandoning user requested failover. A failover happened recently on this instance. Wait and try again.
• The gap after your fix is still measured in minutes. The connection is being reused. Check that the exception handler sets conn = None and that the loop honours it, rather than catching, logging, and carrying on with the same object.
• The shipped version already looks fine. It happens. A reboot with failover sometimes tears the socket down promptly, and then the in-flight insert fails in milliseconds rather than blocking, which hides the largest term. Fail it over again. The two versions separate reliably over three runs, and the spread is worth seeing on its own.
• The writer recovers but the first few inserts are slow. Expected. The promoted instance has a cold buffer cache, and the new standby is still catching up on the data it has to replicate.

Reveal the solution

SRC=solution ./scripts/deploy.sh && ./scripts/failover.sh && ./scripts/measure.py

What you just learned

• The published figures describe RDS, not your application. Failover times for a Multi-AZ DB instance are typically 60 to 120 seconds, and under 35 seconds for a Multi-AZ DB cluster with two readable standbys. What your users experience is that interval plus DNS propagation plus whatever the client does about a broken socket, and only the first term is fixed by choosing a deployment mode.
• Failover moves a DNS record. RDS updates the endpoint’s DNS to point at the promoted instance, and RDS-EVENT-0015 says in its own text that propagation may take a few minutes. AWS asks for a client-side DNS TTL under 30 seconds, and calls out the JVM by name because some configurations never refresh a cached address until the process restarts.
• A socket with no deadline is the single largest term in most of these measurements. An in-flight query against a host that has gone blocks until the kernel exhausts its retransmissions, which on Linux defaults is closer to fifteen minutes than to fifteen seconds. Set the deadline in the driver.
• Exponential backoff suits a service that is overloaded and getting worse. A failover is an absence with a known duration, and a coarse fixed delay against it only adds its own length to the outage.
• RDS Proxy removes the DNS term entirely. Its endpoints keep the same addresses when instances exchange roles, so a client that reconnects reaches the new writer without waiting on a record to propagate. AWS publishes a reduction of up to 66% in failover time for RDS and Aurora behind a proxy, and it is the answer worth reaching for when the application cannot be changed.
• Changing the driver is the other answer. The AWS suite of drivers tracks instance topology instead of relying on DNS, which AWS says brings switchover and failover down to single-digit seconds against tens of seconds for open-source drivers.

Next

The rest of the Solutions Architect Associate lab track is in the README.