Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

10 minutes to close connection after an occurrence of 'query_timeout'. #396

Open
aaronmader opened this issue May 21, 2024 · 3 comments
Open

Comments

@aaronmader
Copy link

Software versions

  • Django: 5.0.4
  • mssql-django: 1.5
  • python: python:3.12.3-bookworm
  • SQL Server: unknown
  • OS: Debian 12.5 (bookworm)

Database Connection Settings

DATABASES = {
    'default': {
        'ENGINE': 'mssql',
        'NAME': os.environ.get('MSSQL_USER'),
        'USER': os.environ.get('MSSQL_USER'),
        'PASSWORD': os.environ.get('MSSQL_PASSWORD'),
        'HOST': os.environ.get('MSSQL_HOST'),
        'OPTIONS': {
            'query_timeout': 1,
        },
    },
}

Problem description and steps to reproduce
Setting the 'query_timeout' option works as expected. The exception is raised after the expected interval ('HYT00', '[HYT00] [Microsoft][ODBC Driver 17 for SQL Server]Query timeout expired (0) (SQLExecDirectW)'). However, when django attempts to close the connection (ex, when you close a django shell), those close operation takes 10 minutes.

To reproduce:

  • Set the the 'query_timeout' option in your settings, as above.
  • Open a django shell, and trigger an occurrence of the timeout.
  • Close the django shell, and notice the time required.
$ python manage.py shell
>>> from transaction.models import Transaction
>>> try:
>>>     # Trigger some slow query.
>>>     objects = list(Transaction.objects.all())
>>> except Exception as e:
>>>     if 'Query timeout expired' in str(e):
>>>         print("successfully triggered the query timeout!")
>>>     raise
>>> [ctrl-D]
now exiting InteractiveConsole...                      # <-- This hangs for 10 minutes??

Expected behavior and actual behavior
I expect the connection closing procedure to be quick, but it takes 10 minutes.

@v-makouz
Copy link

Can you provide an ODBC trace?

@aaronmader
Copy link
Author

Here's the trace:
odbctrace.log

I did my best to isolate the trace to a single process's activity, but there's a bit of startup work caused by django's python manage.py shell

The issue can be see in the last ~30 lines of the trace log.
Namely:

  1. (at 1716383232.298629) The query_timeout is set to 1 second.
  2. (at 1716383232.298917) The slow query is requested.
  3. (at 1716383233.317473) The server returns the timeout response.
  4. (at 1716383235.890952) I press ctrl-d to close the shell. A 'disconnect' is sent.
  5. (at 1716383835.891218) The disconnect is successful (Notice that this is 10 minutes later)

Thanks,

@absci
Copy link
Contributor

absci commented Jun 4, 2024

Hi, the next release of the ODBC driver will contain the bug fix.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

3 participants