Opened 26 hours ago

Closed 25 hours ago

#36263 closed Bug (invalid)

DB connection is not recreated after it closed due to time out.

Reported by: Sivakajan Sivaparan Owned by:
Component: Database layer (models, ORM) Version: 5.1
Severity: Normal Keywords: DB, Connection-close, ensure_connection
Cc: Sivakajan Sivaparan Triage Stage: Unreviewed
Has patch: no Needs documentation: no
Needs tests: no Patch needs improvement: no
Easy pickings: no UI/UX: no

Description

Issue Faced:
When executing a query after a database connectivity loss (lasting more than 6 minutes), Django is unable to recreate a new connection automatically. This issue persists even when using connection.cursor(), saving a model instance (model.save()), or explicitly calling connection.ensure_connection().

However, if the connection is explicitly closed using connection.close(), Django successfully establishes a new connection to the database.

The above exception was the direct cause of the following exception:

Traceback (most recent call last):
  File "/home/ubuntu/environment/db_tester/my_tester/views.py", line 20, in insert_model
    new_model.save()
  File "/home/ubuntu/.local/lib/python3.10/site-packages/django/db/models/base.py", line 892, in save
    self.save_base(
  File "/home/ubuntu/.local/lib/python3.10/site-packages/django/db/models/base.py", line 998, in save_base
    updated = self._save_table(
  File "/home/ubuntu/.local/lib/python3.10/site-packages/django/db/models/base.py", line 1161, in _save_table
    results = self._do_insert(
  File "/home/ubuntu/.local/lib/python3.10/site-packages/django/db/models/base.py", line 1202, in _do_insert
    return manager._insert(
  File "/home/ubuntu/.local/lib/python3.10/site-packages/django/db/models/manager.py", line 87, in manager_method
    return getattr(self.get_queryset(), name)(*args, **kwargs)
  File "/home/ubuntu/.local/lib/python3.10/site-packages/django/db/models/query.py", line 1847, in _insert
    return query.get_compiler(using=using).execute_sql(returning_fields)
  File "/home/ubuntu/.local/lib/python3.10/site-packages/django/db/models/sql/compiler.py", line 1836, in execute_sql
    cursor.execute(sql, params)
  File "/home/ubuntu/.local/lib/python3.10/site-packages/django/db/backends/utils.py", line 122, in execute
    return super().execute(sql, params)
  File "/home/ubuntu/.local/lib/python3.10/site-packages/django/db/backends/utils.py", line 79, in execute
    return self._execute_with_wrappers(
  File "/home/ubuntu/.local/lib/python3.10/site-packages/django/db/backends/utils.py", line 92, in _execute_with_wrappers
    return executor(sql, params, many, context)
  File "/home/ubuntu/.local/lib/python3.10/site-packages/django/db/backends/utils.py", line 100, in _execute
    with self.db.wrap_database_errors:
  File "/home/ubuntu/.local/lib/python3.10/site-packages/django/db/utils.py", line 91, in __exit__
    raise dj_exc_value.with_traceback(traceback) from exc_value
  File "/home/ubuntu/.local/lib/python3.10/site-packages/django/db/backends/utils.py", line 105, in _execute
    return self.cursor.execute(sql, params)
django.db.utils.OperationalError: server closed the connection unexpectedly
        This probably means the server terminated abnormally
        before or while processing the request.
server closed the connection unexpectedly
        This probably means the server terminated abnormally
        before or while processing the request.

[2025-03-18 11:34:35] ERROR my_tester.views: Database connection failed on 11:34:35
Traceback (most recent call last):
  File "/home/ubuntu/.local/lib/python3.10/site-packages/django/db/backends/base/base.py", line 298, in _cursor
    return self._prepare_cursor(self.create_cursor(name))
  File "/home/ubuntu/.local/lib/python3.10/site-packages/django/utils/asyncio.py", line 26, in inner
    return func(*args, **kwargs)
  File "/home/ubuntu/.local/lib/python3.10/site-packages/django/db/backends/postgresql/base.py", line 429, in create_cursor
    cursor = self.connection.cursor()
psycopg2.InterfaceError: connection already closed

Even if it says, connection already closed, I can not create a new healthy connection. If I call close() function and continue, it create a new connection form connection.cursor().

Recreate the Issue:

from django.db import connection
from django.db.utils import OperationalError
from my_tester.models import SimpleModel
import time
import logging

logger = logging.getLogger(__name__)

def insert_model(request):
    logger.info(f"======== Function triggered on:{time.strftime('%H:%M:%S')} ")
    model_name_suffix = int(round(time.time() * 1000))
    query = "INSERT INTO my_tester_simplemodel (model_name, model_description) VALUES (%s, %s);"
    
    for _ in range(200):
        try:
            check_connection(_)
            new_model = SimpleModel(model_name=f"model_{model_name_suffix}_{_}", model_description="model_description")
            new_model.save()
            check_connection(_)
            logger.info(f"Inserted: model_{model_name_suffix}_{_} on {time.strftime('%H:%M:%S')}")
            time.sleep(10)
        except Exception as e:
            logger.error(f"Database connection failed on {time.strftime('%H:%M:%S')}", exc_info=True)
            # connection.close()
            time.sleep(10)

    logger.info(f"+++++++++ Function end on:{time.strftime('%H:%M:%S')}")
    
    return "Models added successfully"
    
def check_connection(iterr):
    try:
        if connection.connection is not None:
            logger.info(f"Database connection is established {iterr} on {time.strftime('%H:%M:%S')}")
        else:
            logger.info(f"Database connection is not established {iterr} on {time.strftime('%H:%M:%S')}")
    except:
        logger.error(f"Connection checker {iterr} error on {time.strftime('%H:%M:%S')}")

In the above code set, I am sending a number of queries in a 10sec time interval. While the queries getting execute, I stop the connection between the Django app and the DB.( I created the application in the cloud9 instance and DB in the AWS RDS, both with the same security group. I can change the inbound rules of the SG and control the connectivity). When stop the connection, the app will wait for nearly 6mins( maybe the default idle session time). After that interval, it will throws the exception as I given above. It continuously throws the exception every 10 sec.

Then I enable the connection, still the django/ensure_connection is not creating a fresh connection at all.

[2025-03-18 08:28:59] INFO my_tester.views: ======== Function triggered on:08:28:59 
[2025-03-18 08:28:59] INFO my_tester.views: Database connection is not established 0 on 08:28:59
[2025-03-18 08:28:59] INFO my_tester.views: Database connection is established 0 on 08:28:59
[2025-03-18 08:28:59] INFO my_tester.views: Inserted: model_1742286539377_0 on 08:28:59
[2025-03-18 08:29:09] INFO my_tester.views: Database connection is established 1 on 08:29:09
[2025-03-18 08:29:09] INFO my_tester.views: Database connection is established 1 on 08:29:09
[2025-03-18 08:29:09] INFO my_tester.views: Inserted: model_1742286539377_1 on 08:29:09
[2025-03-18 08:29:19] INFO my_tester.views: Database connection is established 2 on 08:29:19
[2025-03-18 08:29:19] INFO my_tester.views: Database connection is established 2 on 08:29:19
[2025-03-18 08:35:09] ERROR my_tester.views: Database connection failed on 08:35:09
<Error Mentioned in the description>
[2025-03-18 08:35:19] INFO my_tester.views: Database connection is established 3 on 08:35:19
[2025-03-18 08:37:34] ERROR my_tester.views: Database connection failed on 08:37:34
<Error Mentioned in the description>
[2025-03-18 08:37:44] INFO my_tester.views: Database connection is established 4 on 08:37:44
[2025-03-18 08:39:58] ERROR my_tester.views: Database connection failed on 08:39:58
<Error Mentioned in the description>
[2025-03-18 08:40:08] INFO my_tester.views: Database connection is established 5 on 08:40:08
[2025-03-18 08:42:21] ERROR my_tester.views: Database connection failed on 08:42:21
<Error Mentioned in the description>
[2025-03-18 08:42:31] INFO my_tester.views: Database connection is established 6 on 08:42:31
[2025-03-18 08:44:44] ERROR my_tester.views: Database connection failed on 08:44:44
[2025-03-18 08:44:54] INFO my_tester.views: Database connection is established 7 on 08:44:54
[2025-03-18 08:47:08] ERROR my_tester.views: Database connection failed on 08:47:08

You can see, the connection.connection is not None in every iteration. In the middle of the execution, I reconnect the DB also. But no changes at all.

When I comment out the connection.close() in the code, then execute,

[2025-03-18 15:08:33] INFO my_tester.views: ======== Function triggered on:15:08:33 
[2025-03-18 15:08:33] INFO my_tester.views: Database connection is not established 0 on 15:08:33
[2025-03-18 15:08:33] INFO my_tester.views: Database connection is established 0 on 15:08:33
[2025-03-18 15:08:33] INFO my_tester.views: Inserted: model_1742310513542_0 on 15:08:33
[2025-03-18 15:08:43] INFO my_tester.views: Database connection is established 1 on 15:08:43
[2025-03-18 15:08:43] INFO my_tester.views: Database connection is established 1 on 15:08:43
[2025-03-18 15:08:43] INFO my_tester.views: Inserted: model_1742310513542_1 on 15:08:43
[2025-03-18 15:08:53] INFO my_tester.views: Database connection is established 2 on 15:08:53
[2025-03-18 15:14:43] ERROR my_tester.views: Database connection failed on 15:14:43
Traceback (most recent call last):
  File "/home/ubuntu/.local/lib/python3.10/site-packages/django/db/backends/utils.py", line 105, in _execute
    return self.cursor.execute(sql, params)
psycopg2.OperationalError: server closed the connection unexpectedly
        This probably means the server terminated abnormally
        before or while processing the request.
server closed the connection unexpectedly
        This probably means the server terminated abnormally
        before or while processing the request.


The above exception was the direct cause of the following exception:

Traceback (most recent call last):
  File "/home/ubuntu/environment/db_tester/my_tester/views.py", line 19, in insert_model
    new_model.save()
  File "/home/ubuntu/.local/lib/python3.10/site-packages/django/db/models/base.py", line 892, in save
    self.save_base(
  File "/home/ubuntu/.local/lib/python3.10/site-packages/django/db/models/base.py", line 998, in save_base
    updated = self._save_table(
  File "/home/ubuntu/.local/lib/python3.10/site-packages/django/db/models/base.py", line 1161, in _save_table
    results = self._do_insert(
  File "/home/ubuntu/.local/lib/python3.10/site-packages/django/db/models/base.py", line 1202, in _do_insert
    return manager._insert(
  File "/home/ubuntu/.local/lib/python3.10/site-packages/django/db/models/manager.py", line 87, in manager_method
    return getattr(self.get_queryset(), name)(*args, **kwargs)
  File "/home/ubuntu/.local/lib/python3.10/site-packages/django/db/models/query.py", line 1847, in _insert
    return query.get_compiler(using=using).execute_sql(returning_fields)
  File "/home/ubuntu/.local/lib/python3.10/site-packages/django/db/models/sql/compiler.py", line 1836, in execute_sql
    cursor.execute(sql, params)
  File "/home/ubuntu/.local/lib/python3.10/site-packages/django/db/backends/utils.py", line 122, in execute
    return super().execute(sql, params)
  File "/home/ubuntu/.local/lib/python3.10/site-packages/django/db/backends/utils.py", line 79, in execute
    return self._execute_with_wrappers(
  File "/home/ubuntu/.local/lib/python3.10/site-packages/django/db/backends/utils.py", line 92, in _execute_with_wrappers
    return executor(sql, params, many, context)
  File "/home/ubuntu/.local/lib/python3.10/site-packages/django/db/backends/utils.py", line 100, in _execute
    with self.db.wrap_database_errors:
  File "/home/ubuntu/.local/lib/python3.10/site-packages/django/db/utils.py", line 91, in __exit__
    raise dj_exc_value.with_traceback(traceback) from exc_value
  File "/home/ubuntu/.local/lib/python3.10/site-packages/django/db/backends/utils.py", line 105, in _execute
    return self.cursor.execute(sql, params)
django.db.utils.OperationalError: server closed the connection unexpectedly
        This probably means the server terminated abnormally
        before or while processing the request.
server closed the connection unexpectedly
        This probably means the server terminated abnormally
        before or while processing the request.

[2025-03-18 15:14:53] INFO my_tester.views: Database connection is not established 3 on 15:14:53
<Error as above>
[2025-03-18 15:17:17] INFO my_tester.views: Database connection is not established 4 on 15:17:17
<Error as above>
[2025-03-18 15:19:40] INFO my_tester.views: Database connection is not established 5 on 15:19:40
<Error as above>
[2025-03-18 15:22:04] INFO my_tester.views: Database connection is not established 6 on 15:22:04
[2025-03-18 15:22:23] INFO my_tester.views: Database connection is established 6 on 15:22:23
[2025-03-18 15:22:23] INFO my_tester.views: Inserted: model_1742310513542_6 on 15:22:23
[2025-03-18 15:22:33] INFO my_tester.views: Database connection is established 7 on 15:22:33
[2025-03-18 15:22:33] INFO my_tester.views: Database connection is established 7 on 15:22:33
[2025-03-18 15:22:33] INFO my_tester.views: Inserted: model_1742310513542_7 on 15:22:33

You can see in the command, it says Database connection is not established 6 on 15:22:04, which implies connection.connection is None that time.

Question:
It says, the connection will be closed if the pipe between the DB and the application closed. But in this scenario, it seems the connection is not closed until we explicitly close the connection. Why that happen?

Also, please explain, can CONN_HEALTH_CHECK, CONN_MAX_AGE flags use to solve this type of issues. I tried with these, but no changes regarding of the CONN_HEALTH_CHECK value.(True/False)

Change History (1)

comment:1 by Simon Charette, 25 hours ago

Resolution: invalid
Status: newclosed

Please refer to the database documentation about caveats

If a connection is created in a long-running process, outside of Django’s request-response cycle, the connection will remain open until explicitly closed, or timeout occurs. You can use django.db.close_old_connections() to close all old or unusable connections.

In other words, outside of the request-response cycle Django has no entry point to determine when the connection should be ping'ed to determine if it should be closed and re-opened and performing a ping before every single query is not desirable so CONN_HEALTH_CHECKS has no effect there.

If set to True, existing persistent database connections will be health checked before they are reused in each request performing database access.

You should explicitly call close_old_connections before every code path outside of request-response cycle that interacts with the database and could be idling for longer than your configured connection timeouts.

See #32589 for more details on the above and #24810 about trying to re-open connections automatically when no transaction is active.

Note: See TracTickets for help on using tickets.
Back to Top