Greenstand/treetracker-infrastructure

Tile server OOM crashes and Airflow scheduler restart loop traced to query timeout and memory leak in PGPool.js

Open

#315 aperta il 14 mag 2026

Vedi su GitHub
 (9 commenti) (0 reazioni) (1 assegnatario)HCL (40 fork)auto 404
cloud-engineeringgood first issue

Metriche repository

Star
 (23 star)
Metriche merge PR
 (Metriche PR in attesa)

Descrizione

Tile server OOM crashes and Airflow scheduler restart loop traced to query timeout and memory leak in PGPool.js

Labels: bug infrastructure database high-priority


Background: what triggered this investigation

This investigation started from a broader observation that Kubernetes pods across the cluster were crashing periodically with no obvious common cause. The goal was to find a shared root cause rather than treat each pod's restarts as an isolated problem.

Two specific pods were crashing:

Tile server pods (namespace: tile-server) — confirmed OOM-killed by the Kubernetes node. kubectl describe on pod treetracker-tile-server-76c56645c4-cn2pt shows:

  • Exit code 137 (killed by the OS OOM killer)
  • Exit code 134 (secondary crash, SIGABRT, consistent with post-OOM memory corruption)
  • Memory at time of kill: 2,553,064 Ki (~2.5 GB) against a memory request of 0 (no limit set)
  • Node message: The node was low on resource: memory. Threshold quantity: 100Mi, available: 1448Ki. A tile server rendering 256×256 PNG tiles has no legitimate reason to hold 2.5 GB. This is a memory leak, traced to a specific bug in PGPool.js described below.

Airflow scheduler pod (namespace: airflow) — not crashing, but being killed by its own Kubernetes liveness probe 2,113 times in 39 days. The probe declares the scheduler unhealthy when it cannot open a database session within 10 seconds. This is being caused by database connection exhaustion traced to the same root cause as the tile server memory leak.

Other DB-dependent services (admin-api, wallet-api, earnings-api, field-data-api, treetracker-api, reporting, query) show zero or near-zero restarts over the same 39-day window, confirming the problem is contained to the tile server and Airflow rather than a cluster-wide event.


Components involved

Airflow is the job scheduler Greenstand uses to run recurring data tasks (reporting, tree assignments, data exports). It has a scheduler pod that orchestrates all DAG runs and worker pods that execute them. The scheduler's health is checked every 30 seconds by a Kubernetes liveness probe that opens a database session to verify the scheduler is alive. If that probe fails 5 times consecutively, Kubernetes kills and restarts the scheduler container.

pgpool (namespace: pgpool) sits between all backend services and the production PostgreSQL database (DigitalOcean Managed Postgres). It manages a shared pool of database connections — configured with num_init_children = 40 and max_pool = 2, giving a ceiling of 80 simultaneous connections. All services in the cluster share this pool.

The tile server (namespace: tile-server) serves the map tiles shown on the Greenstand web map. It queries the database to render tree locations at different zoom levels and filters. It has its own internal query cache (PGPool.js) that wraps the PostgreSQL connection pool.

The pre_request_map_clusters DAG is a cache pre-warming job in pre_request_map_clusters_dag.py. It runs every 5 minutes (*/5 * * * *) and makes HTTP requests to the tile server across a range of zoom levels and map name filters, so that tile responses are pre-cached and fast for end users.


The two bugs

Bug 1 — PGPool.js: database errors are silently swallowed and the connection state is never reset

In /app/greenstand/PGPool.js, the fetch() method handles database errors like this:

this.pool.query({ text: sql, values: [] }).then(result => {
  // success path: resolves callbacks, resets isFetching
}).catch(e => {
  log.error("get error when query db:", e);
  // nothing else
});

When the database kills a query (e.g. due to a timeout), the catch block fires — but:

  • isFetching[sql] is never reset to false
  • All queued callbacks in this.queue[sql] are never called
  • The promise returned to the route handler never resolves or rejects
  • The HTTP connection from the caller stays open indefinitely This causes two problems simultaneously:
  1. Memory leak: every subsequent request for the same SQL string pushes another callback into this.queue[sql]. These callbacks and their associated promises are never garbage collected. Over hours and days of the pre-warm DAG firing every 5 minutes, this grows without bound until the pod is OOM-killed by Kubernetes.
  2. Silent hang: the Express route handler never sends a response. Any caller waiting on that HTTP request — including the Airflow pre-warm task — will hang until their own timeout fires. The two tile server pods stuck in ContainerStatusUnknown state (treetracker-tile-server-76c56645c4-cn2pt and treetracker-tile-server-76c56645c4-z8k82, both with 6 restarts, both stuck for ~39 days) are confirmed OOM-killed — exit code 137, memory at kill ~2.5 GB, the node driven to near-exhaustion. The two surviving pods (7kbfj: 10 restarts, slzls: 27 restarts) show the same periodic restart pattern and are likely experiencing the same memory leak at a slower rate, or being restarted before reaching the node memory threshold.

There is also a secondary bug in every route handler's catch block in app.js:

catch(e){
  log.error("got error in handler:", e);
  res.status(500).json({message:"something wrong:" + error}); // `error` is undefined — should be `e`
}

This would throw a ReferenceError if the catch block were ever reached via a path other than a hung promise. It is a latent bug that would mask error responses in future failure modes.

Bug 2 — No statement_timeout on the tile server's database connection

The PostgreSQL connection pool in app.js is created without a statement_timeout:

const pool = new Pool({
  connectionString,
  max,
});

Without this, queries run until DigitalOcean's managed database server kills them at its own threshold — confirmed via worker logs to be approximately 600 seconds. During those 600 seconds, a pgpool child process is held exclusively by that query and unavailable to any other service in the cluster.


How these bugs combine to crash the Airflow scheduler

Step 1 — The pre-warm DAG fires every 5 minutes

pre_request_map_clusters calls lib/pre_request_map_clusters.py, which makes 182 sequential HTTP requests to the tile server:

  • 13 query variants (1 global, 11 named maps, 1 wallet filter)
  • × 14 zoom levels each (zoom 2 through 15)
  • = 182 requests per run

Step 2 — Requests with map_name filters at zoom 12–15 trigger an expensive query

Inside the tile server (/app/greenstand/Map.js), the routing logic sends requests with a map_name parameter at zoom levels 12–15 to SQLCase3. Requests without a map_name at those zoom levels use SQLCase4, which queries a pre-computed clusters table and is fast.

SQLCase3 (/app/greenstand/sqls/SQLCase3.js) runs:

SELECT Unnest(St_clusterwithin(estimated_geometric_location, <radius>))
FROM trees
WHERE active = true
AND trees.estimated_geometric_location && ST_MakeEnvelope(<bounds>, 4326)

ST_ClusterWithin is a PostGIS function that groups nearby geographic points into spatial clusters. On a dataset of approximately 18 million rows, at a tile coordinate of 1/1 which covers a large geographic area, this query consistently runs until the database kills it at 600 seconds.

The pre-warm list contains 10 map name variants (excluding freetown, which is explicitly routed away from SQLCase3 in Map.js), each hitting 4 zoom levels = 40 ST_ClusterWithin queries per 5-minute run.

Step 3 — The database kills the query at 600 seconds; PGPool.js hangs

When the database timeout fires, Bug 1 takes effect: the PGPool.js catch block logs the error and exits without resolving the promise. The tile server's HTTP response never arrives. The Airflow task hangs waiting for it.

Step 4 — Airflow's own HTTP timeout fires around 605 seconds, ending the task

Worker logs show each pre_request_map_cluster task running for almost exactly 605 seconds before Airflow marks it complete. This is Airflow's own HTTP client timeout coinciding with the database's timeout window — not the tile server responding. The Celery worker reports the task as succeeded (clean exit), but the scheduler marks the same execution date as failed.

This creates a retry loop: the task for execution date 2026-05-13 23:40:00 is re-queued immediately and repeatedly:

23:45:37 → started
23:55:42 → worker: succeeded (605s) / scheduler: failed — same execution_date 23:40:00
23:55:45 → started again
00:05:50 → worker: succeeded (605s) / scheduler: failed — same execution_date 23:40:00
00:05:52 → started again
... continues indefinitely

The DAG is configured with retries: 15, retry_delay: timedelta(seconds=1). Each retry holds a pgpool child for up to 600 seconds.

Step 5 — pgpool children are held for 600 seconds, starving the Airflow liveness probe

With Bug 2 in place (no statement_timeout), each tile server query holds a pgpool child for the full 600 seconds. pgpool is configured with connection_life_time = 0, meaning active connections are never aged out by pgpool itself — only when the query completes or is killed by the database.

Step 6 — The scheduler liveness probe times out and Kubernetes restarts the pod

The Airflow scheduler's liveness probe runs every 30 seconds. It opens a database session via create_session() and queries the SchedulerJob table. When pgpool has no available children, this call blocks. The probe has a timeout of 10 seconds and a failure threshold of 5. Once those thresholds are exceeded, Kubernetes kills and restarts the scheduler container.

This has been confirmed via kubectl describe:

  • Liveness probe failed: command timed out: 9,645 occurrences over 39 days
  • Liveness probe failed: UNHEALTHY - 0 alive SchedulerJob: 19,825 occurrences over 39 days
  • Total scheduler restarts: 2,113 in 39 days Each restart causes Airflow to re-adopt orphaned task instances, re-queue them, and continue the cycle.

Blast radius: confirmed contained to tile server and Airflow

To determine whether pgpool exhaustion was affecting other services, restart counts were checked across all DB-dependent namespaces:

Service Restarts Status
treetracker-admin-api 0 Stable
treetracker-earnings-api 0 Stable
treetracker-field-data 0 Stable
treetracker-grower-account-query 0 Stable
treetracker-reporting-api 0 Stable
treetracker-api 1 (34 days ago) Stable
treetracker-wallet-api 0 Stable
treetracker-tile-server (4 pods) 10 / 27 / 6 / 6 2 pods stuck in ContainerStatusUnknown
airflow-scheduler 2,113 Active restart loop

pgpool exhaustion is periodic rather than continuous — connections are held for ~10 minutes per retry cycle, then released. Other services handle brief connection unavailability gracefully and do not have liveness probes with tight DB-dependent timeouts. The blast radius is therefore limited to the tile server (memory leak) and the Airflow scheduler (liveness probe sensitivity).


Zombie DAG assign-new-captures-to-clusters

This DAG ID is a zombie — the DAG was renamed to assign_tree_to_cluster and its original file no longer exists in the repository. It appears in scheduler logs as a failed task on every restart but does not execute or hold connections. It should be cleared from the Airflow metadata database separately but is not driving the restart loop.

The assign_tree_to_cluster DAG (the renamed replacement) runs every 2 hours and is healthy. The clusters table it populates — which SQLCase4 depends on for fast global map tile queries — is being maintained correctly.


Proposed fixes

Three fixes are needed. Fixes 1 and 2 address the tile server directly. Fix 3 reduces the frequency with which the problem is triggered from the Airflow side.


Fix 1 — Add statement_timeout to the tile server's database connection (app.js)

Repo: treetracker-tile-server
File: /app/greenstand/app.js
Who can action: anyone with repo access — a PR can be raised

After the pool is instantiated, add a connect event handler:

// current
const pool = new Pool({
  connectionString,
  max,
});
 
// after fix
const pool = new Pool({
  connectionString,
  max,
});
 
pool.on('connect', (client) => {
  client.query('SET statement_timeout = 30000');
});

pool.on('connect') fires each time a new client is created and added to the pool. Setting statement_timeout = 30000 (30 seconds) there ensures every query through this pool — including SQLCase3 — is killed by the tile server's own DB client at 30 seconds rather than at DigitalOcean's 600-second server-side limit.

30 seconds is based on the fact that normal successful tile renders complete in 30–37 seconds end-to-end (confirmed from worker logs), so the DB query itself completes well under that. Any query still running at 30 seconds is effectively hung and should be killed.

This limits each failed SQLCase3 attempt to holding a pgpool child for 30 seconds instead of 600. That alone should largely stop the Airflow scheduler liveness probe from being starved.


Fix 2 — Fix the error handling in PGPool.js (PGPool.js)

Repo: treetracker-tile-server
File: /app/greenstand/PGPool.js
Who can action: anyone with repo access — a PR can be raised

The catch block in fetch() must reset state and drain the queue so subsequent requests for the same SQL string can retry:

// current
}).catch(e => {
  log.error("get error when query db:", e);
});
 
// after fix
}).catch(e => {
  log.error("get error when query db:", e);
  this.isFetching[sql] = false;
  while(this.queue[sql] && this.queue[sql].length > 0){
    const cb = this.queue[sql].pop();
    cb(e);
  }
});

Without this fix, a single DB error permanently freezes all future requests for that SQL string — callbacks accumulate in memory indefinitely and promises never resolve. This is the direct cause of the tile server memory leak and OOM crashes.

Also fix the ReferenceError in app.js route handlers (all three .png and .grid.json handlers have this):

// current
res.status(500).json({message:"something wrong:" + error});
 
// after fix
res.status(500).json({message:"something wrong:" + e});

Fix 3 — Add execution_timeout and reduce retries in pre_request_map_clusters_dag.py

Repo: treetracker-airflow-dags
File: pre_request_map_clusters_dag.py
Who can action: anyone with repo access — a PR can be raised

# current
'retries': 15,
'retry_delay': timedelta(seconds=1),
# 'execution_timeout': timedelta(seconds=300),
 
# after fix
'retries': 1,
'retry_delay': timedelta(minutes=5),
'execution_timeout': timedelta(seconds=120),

Why these values:

  • execution_timeout: 120s — Normal successful runs complete in 30–37 seconds (confirmed from worker logs). 120 seconds gives 3× headroom for a slow-but-healthy run, while ensuring Airflow terminates the task well before the tile server's own hang can propagate. With Fix 1 in place, the tile server will return an error within 30 seconds for hung queries, so the task should fail fast and cleanly rather than hanging.
  • retries: 1 — One retry handles transient network or tile server hiccups. The current 15 retries at 1-second spacing means a consistently failing task hammers the tile server and pgpool for up to 15 × 120 seconds = 30 minutes before Airflow gives up.
  • retry_delay: 5 minutes — Gives the tile server time to recover between attempts. Note: Fix 3 is most effective after Fixes 1 and 2 are deployed. Without the tile server fixes, the pre-warm task will still hang and the execution_timeout will just cap the damage rather than eliminate it.

Recommended fix order

  1. Fix 2 first (PGPool.js catch block) — stops the memory leak killing tile server pods. No configuration dependency.
  2. Fix 1 second (statement_timeout) — stops 600-second pgpool connection holds, which stops the Airflow scheduler restart loop.
  3. Fix 3 third (execution_timeout + retry reduction) — reduces the trigger frequency once the tile server is no longer silently hanging. Fixes 1 and 2 are both in treetracker-tile-server and can be combined into a single PR.

Open questions

  1. Why does the Airflow worker report succeeded while the scheduler marks the same task failed? We know the tile server hangs (Bug 1) and that Airflow's HTTP client timeout coincides with the DB timeout window at ~605 seconds. But the precise mechanism causing the scheduler/worker disagreement has not been confirmed end-to-end. Fix 3 (execution_timeout) should resolve the symptom regardless, but understanding this fully may surface additional issues in lib/pre_request.py.
  2. What is the exact bounding box for tile 1/1 at zoom 12–15? The pre-warm DAG requests this tile coordinate at all zoom levels. At zoom 12–15, tile 1/1 likely covers a large but not necessarily global area. If the bounding box is tighter than assumed, SQLCase3 may be less expensive than the 600-second ceiling suggests. This does not change the fix recommendations but affects whether a longer-term SQL optimisation for SQLCase3 is worthwhile.
  3. Does wallet=FinorX route to SQLCase3 at zoom 12–15? The routing in Map.js branches on tree count (Case3 if ≤ 2,000 trees, Case1WithZoomTarget otherwise). If FinorX has fewer than 2,000 trees, it adds 4 more ST_ClusterWithin calls per pre-warm run.

Evidence summary

Finding Source
2,113 scheduler restarts in 39 days kubectl describe pod -n airflow airflow-scheduler-7b87ff6869-hshsm
Liveness probe kills scheduler — not a crash (exit code 0) Same — Reason: Completed; event: failed liveness probe, will be restarted
Probe timed out 9,645 times; 0-jobs failure 19,825 times Same — Warning Unhealthy events
pre_request_map_cluster for 23:40:00 running continuously at ~605s kubectl logs -n airflow airflow-worker-0 -c airflow-worker
Worker reports succeeded; scheduler marks failed Scheduler logs (--previous)
PGPool.js catch block never resolves promise or resets state /app/greenstand/PGPool.js on tile server pod
No statement_timeout on pg.Pool instantiation /app/greenstand/app.js on tile server pod
SQLCase3 uses ST_ClusterWithin on full trees table /app/greenstand/sqls/SQLCase3.js on tile server pod
map_name=* at zoom 12–15 routes to SQLCase3 /app/greenstand/Map.js on tile server pod
pgpool ceiling: 80 connections, child_life_time=300, connection_life_time=0 /config/pgpool.conf on treetracker-pgpool-6f7c468565-wb42q
All other DB-dependent services show 0 restarts over 39 days kubectl get pods -A filtered by namespace
2 tile server pods stuck in ContainerStatusUnknown (6 restarts each) kubectl get pods -n tile-server
assign-new-captures-to-clusters DAG file absent from repo (zombie) find /opt/airflow/dags -name '*assign*' on airflow worker
assign_tree_to_cluster (renamed DAG) runs successfully every 2 hours Scheduler logs

Guida contributor