Behind the Scenes of a Long EVE Online Downtime

Behind the Scenes of a Long EVE Online Downtime

Date: August 7, 2015 Author: CCP Goliath (with CCP Masterplan)

This dev blog documents the extended downtime EVE Online experienced on July 15th, 2015, shared because many players work in IT and might appreciate the technical details of managing a unique game cluster.

Background

Historically, EVE experienced extremely lengthy downtimes spanning multiple days. On July 15th, the server was inaccessible for 699 minutes—longer than the June 2013 downtimes but shorter than the 963-minute outage during the 2011 Incarna launch. Currently, standard reboots take approximately 7 minutes, with deployments typically completing within the allotted 30-minute window.

Startup Process

The Tranquility (TQ) cluster comprises roughly 250 server nodes that must coordinate during startup. The process assigns node IDs, establishes network connections between nodes, allocates solar systems to specific nodes, and loads necessary operational data. A master node called “Polaris” orchestrates this sequence, which progresses through stages -4 through 0. Each stage requires all nodes to report completion before advancing.

The stages include:

  • Stage -4: Node startup and database connection
  • Stage -3: Network connections established between all nodes
  • Stage -2: Address cache primed for routing information
  • Stage -1: Startup services initialized and data preloading begins
  • Stage 0: Cluster declared ready

Incident Timeline

The deployment of an Aegis Sovereignty follow-up patch was expected to be routine, as test servers had successfully processed the update. However, the deployment tool encountered failures requiring reboot before 11:30. A second deployment succeeded, and startup began at 11:42. By 11:46, twelve nodes were stuck, preventing successful startup.

After the classic troubleshooting step of rebooting, 41 nodes remained stuck in stage “-1”. The team enabled VIP access (restricting to developer accounts) and redeployed to rule out locks and conflicts. After two more failed startups, EVE programmers joined operations to investigate the code while developers explored rollback possibilities. Although the code functioned properly on test servers, they decided to test a rollback to the previous day’s build.

Operations checked hardware and OS systems, particularly since infrastructure changes had occurred recently. They removed the server hosting the Polaris node from the cluster and selected a replacement on different hardware, but this produced no improvement.

The team deployed the original TQ build to Singularity test server (which contains DUST data and services that other test servers lack) and found it started successfully. They noticed the EVE process was attempting communication through an IBM USB Remote NDIS Network Device—a management interface using a self-signed IP address with no datacenter routing. They disabled this interface on TQ, disabled CREST and associated services, renamed the server package, and retried. At 14:21, startup completed but 53 nodes remained stuck at “-1”.

Around 15:29, developers proposed emptying new sovereignty records from the database to test whether this data caused issues. They reasoned that Tuesday’s startup involved fresh sovereignty structures before any campaigns or vulnerability windows were generated. QA personnel created massive amounts of test data on Singularity—nearly double TQ’s sovereignty reinforcement events and vulnerability windows—yet it continued starting perfectly. Testing confirmed the script worked on Duality, and it was deployed to TQ at 16:33.

After running the script and confirming empty tables, startup progressed successfully through all stages, reaching stage 0. However, opening with deleted sovereignty data was unacceptable, so investigation continued with approximately 8 EVE programmers and several operations staff.

By 17:10, only vulnerability window data was re-added. The successful startup indicated that campaigns themselves caused the issue. The remaining campaign data was re-added to the database.

The team formulated a theory: during startup, nodes running solar systems with sovereignty campaigns must query nodes managing related alliances to determine the alliance’s chosen capital system. Due to a configuration override temporarily shortening the standard 7-day capital system change delay, cross-node calls might deadlock. One node awaits the alliance node’s response while the alliance node waits for acknowledgment of capital status updates. They submitted code removing the configurable capital delay, but the 18:12 startup still showed 51 stuck nodes.

Key findings at this point:

  • Startup without campaign data succeeded on TQ and all test servers
  • Startup with ~300 campaigns failed on TQ but succeeded on test servers
  • Eliminating capital-related cross-node calls made no difference
  • The system needed experiments isolating the specific problem point

They completely removed campaign loading at startup (preventing command node spawning but allowing normal structure loading). This experimental hotfix succeeded at 19:15. They then tested delayed, asynchronous campaign loading after other startup processes completed.

Perforce sync hangs and unrelated storage issues caused delays, but pizza arrived at 19:48 during the third hotfix deployment. TQ failed to start again despite the asynchronous loading approach, which was surprising since campaigns should have loaded independently. They redeployed hotfix #2 for additional experimentation.

With all nodes running and solar systems verified loaded, they opened a Python console for real-time commands and observations. Initial checks confirmed no campaigns were loaded. When requesting all nodes to load campaigns, the cluster became slow and unresponsive within minutes. Several nodes died and dropped from the cluster, reducing the total from approximately 250 to around 200. Running the campaign loading sequence again produced the same result—cluster unresponsiveness and additional node deaths.

A critical insight emerged: perhaps the problem wasn’t campaigns themselves but the logging surrounding them. With the cluster in a degraded state from dead nodes, they requested a reboot while staying on hotfix #2.

They modified campaign loading functions to perform database operations normally but disabled all logging operations. Re-running the same test completed almost instantly with no cluster issues. All campaigns loaded successfully. Repeating the second load test also completed instantly, reporting no new campaigns needing loading.

Running the test again with logging re-enabled caused the cluster to regress to earlier problematic behavior with node deaths. They discovered that the logging channel used by the campaign system on TQ degraded node performance to the point where nodes dropped from the cluster.

(Note: These developer testing channels differ from activity logs visible in character wallets or used by customer service GMs.)

Hotfix #5 was requested at 21:48, removing all campaign system logging while keeping code otherwise unchanged. Deployed at 22:07, it produced a successful startup by 22:22. VIP checks revealed only a duplicate campaign requiring cleanup. CREST came back online at 22:38, and VIP restrictions were lifted at 22:41, reopening TQ to all players.

Aftermath – Monday, July 20th

To understand why one specific log channel on Tranquility caused extreme stability issues while identical channels on test servers functioned normally, they scheduled VIP time for experiments. Their goal was finding the simplest reproducible code demonstrating the symptoms. After testing on Singularity and Duality without triggering the error, they proceeded on TQ.

They prepared escalating experimental steps and connected to a TQ node’s Python console for interactive investigation. Initially, they validated two logging channels—a generic channel and the sovereignty campaign-specific channel—by executing test logging on a single node. Observing output through Splunk confirmed both channels worked correctly.

Running step 1a (generic logger output) on all 250 nodes in parallel produced 250 log entries instantly. Repeating with step 1b (campaign logger) produced identical results.

Then they increased logging volume: step 2a logged the same line 500 times per node to the generic channel, while step 2b performed identical logging to the campaign channel.

Running step 2a across all nodes completed instantly with 125,000 log lines (250×500) appearing on Splunk—substantial volume but manageable in small bursts. Running step 2b produced correct log quantities in Splunk, but command response was delayed. After several minutes, the console became responsive again, revealing that several nodes had not responded in time and were now showing as dead.

This innocent logging action had caused nodes to time-out and drop from the cluster. They didn’t need complex campaign or database operations to reproduce dead nodes—simple logging achieved this result. “When a developer cannot rely on simple logging actions to not kill his production server, he is going to have a bad day.”

They never observed this behavior on test servers before or since. Something unique to TQ’s operation or configuration caused this logging behavior on specific channels. While TQ operates at different hardware scale, other experiments suggested scale alone wasn’t responsible.

The investigation into why this logging behavior occurs exclusively on TQ with specific log channels remained ongoing at the time of writing.