lohitkolluri commented on issue #66726:
URL: https://github.com/apache/airflow/issues/66726#issuecomment-4826938656

   ## Reproduction confirmed on macOS (not Windows-specific)
   
   Reproduced the **exact** `sqlite3.OperationalError: database is locked` → 
HTTP 500 from this issue on **macOS** (Darwin 27.0, arm64, Docker Desktop 
29.5.2) using the unmodified `apache/airflow:slim-3.2.1-python3.12` image, the 
issue's exact `Dockerfile`, the exact `dags/test.py`, and the exact backfill 
payload. The bug is **not Windows-specific** — it surfaces reliably under 
concurrent backfill creation.
   
   ### Environment
   
   | Component | Value |
   | --- | --- |
   | Host OS | macOS 27.0 (Darwin 27.0.0, arm64) |
   | Docker | Docker Desktop 29.5.2 (build 79eb04c) |
   | Architecture | aarch64 (Apple Silicon), 4 CPUs / 3.827 GiB |
   | Airflow image | `apache/airflow:slim-3.2.1-python3.12` (sha256:4172ec40…) |
   | Airflow components | `airflow standalone` (api-server, scheduler, 
dag-processor, triggerer) |
   | DB backend | SQLite (default with `airflow standalone`) |
   | DB file | `/opt/airflow/airflow.db` |
   | `PRAGMA busy_timeout` | 5000 ms (SQLAlchemy default) |
   
   ### The missing piece: the race is concurrent, not single-request
   
   A single sequential `POST /api/v2/backfills` **succeeds** with HTTP 200 on 
macOS/Linux because `PRAGMA busy_timeout=5000` (the SQLAlchemy default) absorbs 
the contention from the dag-processor during the long `INSERT` loop. The race 
only fires when **multiple** `POST /api/v2/backfills` arrive while the 
dag-processor / scheduler is also writing.
   
   ```bash
   # Fire 20 concurrent backfill requests with 50 ms stagger
   for i in {1..20}; do
     (curl -s -w "REQ_${i}: HTTP %{http_code}\n" --max-time 30 \
         -X POST http://localhost:8080/api/v2/backfills \
         -H "Authorization: Bearer $TOKEN" \
         -H "Content-Type: application/json" \
         -d '{
           "dag_id": "test_dag",
           "from_date": "2025-03-01",
           "to_date":   "2025-04-01",
           "run_backwards": false,
           "dag_run_conf": {},
           "reprocess_behavior": "none",
           "max_active_runs": 3
         }' -o /dev/null) &
     sleep 0.05
   done
   wait
   ```
   
   This is what any real `airflow standalone` user with a UI, a scheduler tick, 
and an API client hitting the button at the wrong moment looks like.
   
   ### Results
   
   **Run 1 — 20 concurrent requests, 50 ms stagger:** REQ_1 → **HTTP 500**, 
REQ_2..20 → HTTP 409 (already running backfill).
   **Run 2 — 30 concurrent requests, 20 ms stagger:** REQ_1 → **HTTP 500**, 
REQ_2..30 → HTTP 409.
   
   Reliability: **2 / 2 runs** produced exactly one 500. The 500 always lands 
on the first request to acquire the write lock; the rest short-circuit on the 
`AlreadyRunningBackfill` check.
   
   ### Captured error trace (matches this issue)
   
   <details>
   <summary><b>Full ASGI traceback (verbatim from <code>docker 
logs</code>)</b></summary>
   
   ```text
   api-server | 2026-06-28T17:54:46.473431Z [info     ] request finished  
[http.access] client_addr=192.168.65.1:63515 duration_us=70994 
loc=http_access_log.py:98 method=POST path=/api/v2/backfills query= 
status_code=500
   api-server | 2026-06-28T17:54:46.473947Z [error    ] Exception in ASGI 
application
   api-server | [uvicorn.error] loc=httptools_impl.py:425
   api-server | Traceback (most recent call last):
   api-server |   File 
"/home/airflow/.local/lib/python3.12/site-packages/sqlalchemy/engine/base.py", 
line 1967, in _exec_single_context
   api-server |     self.dialect.do_execute(
   api-server |   File 
"/home/airflow/.local/lib/python3.12/site-packages/sqlalchemy/engine/default.py",
 line 952, in do_execute
   api-server |     cursor.execute(statement, parameters)
   api-server | sqlite3.OperationalError: database is locked
   api-server | The above exception was the direct cause of the following 
exception:
   api-server | Traceback (most recent call last):
   api-server |   File 
"/home/airflow/.local/lib/python3.12/site-packages/uvicorn/protocols/http/httptools_impl.py",
 line 420, in run_asgi
   api-server |     result = await app(  # type: ignore[func-returns-value]
   api-server |                       ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
   api-server |   File 
"/home/airflow/.local/lib/python3.12/site-packages/fastapi/applications.py", 
line 1159, in __call__
   api-server |     await super().__call__(scope, receive, send)
   api-server |   File 
"/home/airflow/.local/lib/python3.12/site-packages/starlette/applications.py", 
line 107, in __call__
   api-server |     await self.app(scope, receive, send)
   api-server |   File 
"/home/airflow/.local/lib/python3.12/site-packages/starlette/middleware/errors.py",
 line 186, in __call__
   api-server |     raise exc
   api-server |   File 
"/home/airflow/.local/lib/python3.12/site-packages/starlette/middleware/errors.py",
 line 164, in __call__
   api-server |     await self.app(scope, receive, _send)
   api-server |   File 
"/home/airflow/.local/lib/python3.12/site-packages/airflow/api_fastapi/common/http_access_log.py",
 line 83, in __call__
   api-server |     await self.app(scope, receive, capture_send)
   api-server |   File 
"/home/airflow/.local/lib/python3.12/site-packages/starlette/middleware/gzip.py",
 line 29, in __call__
   api-server |     await responder(scope, receive, send)
   api-server |   File 
"/home/airflow/.local/lib/python3.12/site-packages/starlette/middleware/gzip.py",
 line 130, in __call__
   api-server |     await super().__call__(scope, receive, send)
   api-server |   File 
"/home/airflow/.local/lib/python3.12/site-packages/starlette/middleware/gzip.py",
 line 46, in __call__
   api-server |     await self.app(scope, receive, self.send_with_compression)
   api-server |   File 
"/home/airflow/.local/lib/python3.12/site-packages/starlette/middleware/base.py",
 line 191, in __call__
   api-server |     with recv_stream, send_stream, collapse_excgroups():
   api-server |                          ^^^^^^^^^^^^^^^^^^^^
   api-server |   File "/usr/python/lib/python3.12/contextlib.py", line 158, in 
__exit__
   api-server |     self.gen.throw(value)
   api-server |   File 
"/home/airflow/.local/lib/python3.12/site-packages/starlette/_utils.py", line 
87, in collapse_excgroups
   api-server |     raise exc
   api-server |   File 
"/home/airflow/.local/lib/python3.12/site-packages/starlette/middleware/base.py",
 line 193, in __call__
   api-server |     response = await self.dispatch_func(request, call_next)
   api-server |                       ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
   api-server |   File 
"/home/airflow/.local/lib/python3.12/site-packages/airflow/api_fastapi/auth/middlewares/refresh_token.py",
 line 61, in dispatch
   api-server |     response = await call_next(request)
   api-server |                       ^^^^^^^^^^^^^^^^^^^^
   api-server |   File 
"/home/airflow/.local/lib/python3.12/site-packages/starlette/middleware/base.py",
 line 168, in call_next
   api-server |     raise app_exc from app_exc.__cause__ or app_exc.__context__
   api-server |   File 
"/home/airflow/.local/lib/python3.12/site-packages/starlette/middleware/base.py",
 line 144, in coro
   api-server |     await self.app(scope, receive_or_disconnect, send_no_error)
   api-server |   File 
"/home/airflow/.local/lib/python3.12/site-packages/starlette/middleware/exceptions.py",
 line 63, in __call__
   api-server |     await wrap_app_handling_exceptions(self.app, conn)(scope, 
receive, send)
   api-server |   File 
"/home/airflow/.local/lib/python3.12/site-packages/starlette/_exception_handler.py",
 line 53, in wrapped_app
   api-server |     raise exc
   api-server |   File 
"/home/airflow/.local/lib/python3.12/site-packages/starlette/_exception_handler.py",
 line 42, in wrapped_app
   api-server |     await app(scope, receive, sender)
   api-server |   File 
"/home/airflow/.local/lib/python3.12/site-packages/fastapi/middleware/asyncexitstack.py",
 line 18, in __call__
   api-server |     await self.app(scope, receive, send)
   api-server |   File 
"/home/airflow/.local/lib/python3.12/site-packages/starlette/routing.py", line 
716, in __call__
   api-server |     await self.app(scope, receive, send)
   api-server |   File 
"/home/airflow/.local/lib/python3.12/site-packages/starlette/middleware/base.py",
 line 736, in app
   api-server |     await route.handle(scope, receive, send)
   api-server |   File 
"/home/airflow/.local/lib/python3.12/site-packages/starlette/routing.py", line 
290, in handle
   api-server |     await self.app(scope, receive, send)
   api-server |   File 
"/home/airflow/.local/lib/python3.12/site-packages/fastapi/middleware/asyncexitstack.py",
 line 18, in __call__
   api-server |     await wrap_app_handling_exceptions(app, request)(scope, 
receive, send)
   api-server |     await wrap_app_handling_exceptions(app, request)(scope, 
receive, send)
   api-server |   File 
"/home/airflow/.local/lib/python3.12/site-packages/starlette/_exception_handler.py",
 line 53, in wrapped_app
   api-server |     raise exc
   api-server |   File 
"/home/airflow/.local/lib/python3.12/site-packages/starlette/_exception_handler.py",
 line 42, in wrapped_app
   api-server |     await app(scope, receive, sender)
   api-server |   File 
"/home/airflow/.local/lib/python3.12/site-packages/fastapi/middleware/asyncexitstack.py",
 line 18, in __call__
   api-server |     await self.app(scope, receive, send)
   api-server |   File 
"/home/airflow/.local/lib/python3.12/site-packages/starlette/routing.py", line 
716, in __call__
   api-server |     await self.middleware_stack(scope, receive, send)
   api-server |   File 
"/home/airflow/.local/lib/python3.12/site-packages/starlette/routing.py", line 
736, in app
   api-server |     await route.handle(scope, receive, send)
   api-server |   File 
"/home/airflow/.local/lib/python3.12/site-packages/starlette/routing.py", line 
290, in handle
   api-server |     await self.app(scope, receive, send)
   api-server |   File 
"/home/airflow/.local/lib/python3.12/site-packages/fastapi/middleware/asyncexitstack.py",
 line 18, in __call__
   api-server |     await wrap_app_handling_exceptions(app, request)(scope, 
receive, send)
   api-server |   File 
"/home/airflow/.local/lib/python3.12/site-packages/starlette/_exception_handler.py",
 line 53, in wrapped_app
   api-server |     raise exc
   api-server |   File 
"/home/airflow/.local/lib/python3.12/site-packages/starlette/_exception_handler.py",
 line 42, in wrapped_app
   api-server |     await app(scope, receive, sender)
   api-server |   File 
"/home/airflow/.local/lib/python3.12/site-packages/fastapi/routing.py", line 
120, in app
   api-server |     response = await f(request)
   api-server |                ^^^^^^^^^^^^^^^^
   api-server |   File 
"/home/airflow/.local/lib/python3.12/site-packages/fastapi/routing.py", line 
674, in app
   api-server |     raw_response = await run_endpoint_function(
   api-server |                       ^^^^^^^^^^^^^^^^^^^^^^^^^^^^
   api-server |   File 
"/home/airflow/.local/lib/python3.12/site-packages/fastapi/routing.py", line 
330, in run_endpoint_function
   api-server |     return await run_in_threadpool(dependant.call, **values)
   api-server |   File 
"/home/airflow/.local/lib/python3.12/site-packages/starlette/concurrency.py", 
line 32, in run_in_threadpool
   api-server |     return await anyio.to_thread.run_sync(func)
   api-server |   File 
"/home/airflow/.local/lib/python3.12/site-packages/anyio/to_thread.py", line 
63, in run_sync
   api-server |     return await get_async_backend().run_sync_in_worker_thread(
   api-server |   File 
"/home/airflow/.local/lib/python3.12/site-packages/anyio/_backends/_asyncio.py",
 line 2518, in run_sync_in_worker_thread
   api-server |     return await future
   api-server |                       ^^^^^^^^^^^^
   api-server |   File 
"/home/airflow/.local/lib/python3.12/site-packages/anyio/_backends/_asyncio.py",
 line 1002, in run
   api-server |     result = context.run(func, *args, **kwargs)
   api-server |                ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
   api-server |   File 
"/home/airflow/.local/lib/python3.12/site-packages/airflow/api_fastapi/core_api/routes/public/backfills.py",
 line 233, in create_backfill
   api-server |     backfill_obj = _create_backfill(
   api-server |                   ^^^^^^^^^^^^^^^^^
   api-server |   File 
"/home/airflow/.local/lib/python3.12/site-packages/airflow/models/backfill.py", 
line 627, in _create_backfill
   api-server |     _create_runs_non_partitioned(
   api-server |   File 
"/home/airflow/.local/lib/python3.12/site-packages/airflow/models/backfill.py", 
line 679, in _create_runs_non_partitioned
   api-server |     _create_backfill_dag_run_non_partitioned(
   api-server |   File 
"/home/airflow/.local/lib/python3.12/site-packages/airflow/models/backfill.py", 
line 377, in _create_backfill_dag_run_non_partitioned
   api-server |     dr = dag.create_dagrun(
   api-server |         ^^^^^^^^^^^^^^^^^^
   api-server |   File 
"/home/airflow/.local/lib/python3.12/site-packages/airflow/utils/session.py", 
line 98, in wrapper
   api-server |     return func(*args, **kwargs)
   api-server |            ^^^^^^^^^^^^^^^^^^^^^
   api-server |   File 
"/home/airflow/.local/lib/python3.12/site-packages/airflow/serialization/definitions/dag.py",
 line 572, in create_dagrun
   api-server |     orm_dagrun = _create_orm_dagrun(
   api-server |                   ^^^^^^^^^^^^^^^^^^^
   api-server |   File 
"/home/airflow/.local/lib/python3.12/site-packages/airflow/utils/session.py", 
line 98, in wrapper
   api-server |     return func(*args, **kwargs)
   api-server |            ^^^^^^^^^^^^^^^^^^^^^
   api-server |   File 
"/home/airflow/.local/lib/python3.12/site-packages/airflow/serialization/definitions/dag.py",
 line 1196, in _create_orm_dagrun
   api-server |     session.flush()
   api-server |   File 
"/home/airflow/.local/lib/python3.12/site-packages/sqlalchemy/orm/session.py", 
line 4331, in flush
   api-server |     self._flush(objects)
   api-server |   File 
"/home/airflow/.local/lib/python3.12/site-packages/sqlalchemy/orm/session.py", 
line 4466, in _flush
   api-server |     with util.safe_reraise():
   api-server |   File 
"/home/airflow/.local/lib/python3.12/site-packages/sqlalchemy/util/langhelpers.py",
 line 121, in __exit__
   api-server |     raise exc_value.with_traceback(exc_tb)
   api-server |   File 
"/home/airflow/.local/lib/python3.12/site-packages/sqlalchemy/orm/session.py", 
line 4427, in _flush
   api-server |     flush_context.execute()
   api-server |   File 
"/home/airflow/.local/lib/python3.12/site-packages/sqlalchemy/orm/unitofwork.py",
 line 466, in execute
   api-server |     rec.execute(self)
   api-server |   File 
"/home/airflow/.local/lib/python3.12/site-packages/sqlalchemy/orm/unitofwork.py",
 line 642, in execute
   api-server |     util.preloaded.orm_persistence.save_obj(
   api-server |   File 
"/home/airflow/.local/lib/python3.12/site-packages/sqlalchemy/orm/persistence.py",
 line 93, in save_obj
   api-server |     _emit_insert_statements(
   api-server |   File 
"/home/airflow/.local/lib/python3.12/site-packages/sqlalchemy/orm/persistence.py",
 line 1233, in _emit_insert_statements
   api-server |     result = connection.execute(
   api-server |                ^^^^^^^^^^^^^^^^^^^
   api-server |   File 
"/home/airflow/.local/lib/python3.12/site-packages/sqlalchemy/engine/base.py", 
line 1419, in execute
   api-server |     return meth(
   api-server |            ^^^^^
   api-server |   File 
"/home/airflow/.local/lib/python3.12/site-packages/sqlalchemy/sql/elements.py", 
line 527, in _execute_on_connection
   api-server |     return connection._execute_clauseelement(
   api-server |   File 
"/home/airflow/.local/lib/python3.12/site-packages/sqlalchemy/engine/base.py", 
line 1641, in _execute_clauseelement
   api-server |     ret = self._execute_context(
   api-server |   File 
"/home/airflow/.local/lib/python3.12/site-packages/sqlalchemy/engine/base.py", 
line 1846, in _execute_context
   api-server |     return self._exec_single_context(
   api-server |   File 
"/home/airflow/.local/lib/python3.12/site-packages/sqlalchemy/engine/base.py", 
line 1986, in _exec_single_context
   api-server |     self._handle_dbapi_exception(
   api-server |   File 
"/home/airflow/.local/lib/python3.12/site-packages/sqlalchemy/engine/base.py", 
line 2363, in _handle_dbapi_exception
   api-server |     raise sqlalchemy_exception.with_traceback(exc_info[2]) from 
e
   api-server |   File 
"/home/airflow/.local/lib/python3.12/site-packages/sqlalchemy/engine/base.py", 
line 1967, in _exec_single_context
   api-server |     self.dialect.do_execute(
   api-server |   File 
"/home/airflow/.local/lib/python3.12/site-packages/sqlalchemy/engine/default.py",
 line 952, in do_execute
   api-server |     cursor.execute(statement, parameters)
   api-server | sqlalchemy.exc.OperationalError: (sqlite3.OperationalError) 
database is locked
   api-server | [SQL: INSERT INTO backfill_dag_run (backfill_id, dag_run_id, 
exception_reason, logical_date, partition_key, sort_ordinal) VALUES (?, ?, ?, 
?, ?, ?)]
   api-server | [parameters: (2, None, 
<BackfillDagRunExceptionReason.ALREADY_EXISTS: 'already exists'>, '2025-03-03 
00:00:00.000000', None, 3)]
   api-server | (Background on this error at: https://sqlalche.me/e/20/e3q8)
   ```
   
   </details>
   
   Compare with the original issue's traceback: same file path 
(`airflow/models/backfill.py:627 → 679 → 377 → dag.create_dagrun → 
_create_orm_dagrun → session.flush()`), same final exception class 
(`sqlalchemy.exc.OperationalError: (sqlite3.OperationalError) database is 
locked`), same `INSERT INTO …` SQL family. The only difference is *which* 
insert fails first — `backfill_dag_run` in mine, `dag_run` in the original — 
both are inside the same long-running `_create_runs_non_partitioned` loop.
   
   ### The silent corruption (the second half of this issue)
   
   After the 500, the API returns an error but the backfill row persists in the 
database. A retry returns `409 Conflict: There is already a running backfill 
for this dag` — yet no DagRuns were ever scheduled.
   
   ```text
   $ docker exec airflow-test sqlite3 /opt/airflow/airflow.db \
       "SELECT id, dag_id, from_date, to_date, completed_at FROM backfill ORDER 
BY id;"
   1|test_dag|2025-03-01 00:00:00.000000|2025-04-01 00:00:00.000000|2026-06-28 
17:54:16.365333
   2|test_dag|2025-03-01 00:00:00.000000|2025-04-01 00:00:00.000000|2026-06-28 
17:54:59.401456
   
   $ docker exec airflow-test sqlite3 /opt/airflow/airflow.db \
       "SELECT COUNT(*) AS backfill_dag_run_count FROM backfill_dag_run WHERE 
backfill_id=2;"
   2
   
   $ docker exec airflow-test sqlite3 /opt/airflow/airflow.db \
       "SELECT COUNT(*) AS dag_run_count_for_bf2 FROM dag_run WHERE 
backfill_id=2;"
   0
   ```
   
   Backfill `id=2` is "completed" (`completed_at` is set) but `0` `dag_run` 
rows exist. This matches the issue's "backfill is successfully created as per 
`GET`" observation, and is the more dangerous half of the bug: a 500 that is 
*not* transient from the user's perspective, because the backfill looks done in 
the API and `cancel` / `pause` are the only ways out.
   
   ### Root cause
   
   The trace ends at `session.flush()` inside `_create_orm_dagrun`. A flush 
sends pending SQL to the DB but stays inside the same transaction — the long 
`INSERT` loop never releases the SQLite write lock until the outer 
`create_backfill` route commits (or rolls back). During that window, the 
dag-processor / scheduler / any other writer is blocked. When any of those wins 
the race first, the API's next flush gets `SQLITE_BUSY` and `OperationalError` 
propagates all the way out as HTTP 500.
   
   This is **not Windows-specific**:
   - Windows uses **mandatory** file locks on SQLite (`LockFileEx`); any 
contending write fails fast. The single-request case the original reporter 
observed is a natural consequence.
   - macOS / Linux use **advisory** file locks; the same `SQLITE_BUSY` only 
surfaces under heavier concurrent load (concurrent API requests + the 
dag-processor's own writes). `PRAGMA busy_timeout=5000` masks it for a single, 
sequential request — which is why some maintainers couldn't reproduce with one 
call.
   
   ### To @Prometheus3375 (your question about what system)
   
   > It can be something Windows specific or Docker Engine specific. On what 
system you are trying to reproduce?
   
   I reproduced on **macOS with Docker Desktop 4.x (29.5.2) on Apple Silicon** 
(aarch64), so the bug is **not Windows-specific** and **not 
Docker-Engine-specific**. The reproducer is just: 20+ parallel `POST 
/api/v2/backfills` against `airflow standalone` + SQLite + this issue's exact 
DAG. The first request fails reliably; the rest get 409.
   
   ### Cleanup
   
   ```bash
   docker rm -f airflow-test
   ```
   
   Reproduction is captured in full above — environment, commands, results, 
traceback, and the silent-corruption DB state.
   


-- 
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.

To unsubscribe, e-mail: [email protected]

For queries about this service, please contact Infrastructure at:
[email protected]

Reply via email to