jazzband / django-debug-toolbar

A configurable set of panels that display various debug information about the current request/response.
https://django-debug-toolbar.readthedocs.io/
BSD 3-Clause "New" or "Revised" License
8.07k stars 1.05k forks source link

Just Enabling Debug Toolbar as Middleware creates Delays of Several Seconds on each request #1927

Closed QBH3 closed 1 month ago

QBH3 commented 4 months ago

in debug_toolbar/middleware.py is following code:

def show_toolbar(request):
    """
    Default function to determine whether to show the toolbar on a given page.
    """
    internal_ips = list(settings.INTERNAL_IPS)

    try:
        # This is a hack for docker installations. It attempts to look
        # up the IP address of the docker host.
        # This is not guaranteed to work.
        docker_ip = (
            # Convert the last segment of the IP address to be .1
            ".".join(socket.gethostbyname("host.docker.internal").rsplit(".")[:-1])
            + ".1"
        )
        internal_ips.append(docker_ip)
    except socket.gaierror:
        # It's fine if the lookup errored since they may not be using docker
        pass
    return settings.DEBUG and request.META.get("REMOTE_ADDR") in internal_ips

on every request it tries to resolve host.docker.internal which might lead to a timeout from the resolver running locally.

I believe at least this behaviour should be described in the documentation and that it might cause problems with certain resolvers.

Also I believe it should be sufficient to do this name resolution only once per server startup and not at every request.

Another way might be to use the documentation to decribe how to add host.docker.internal to INTERNAL_IPS if a user is inclined to do so.

What do you think?

tim-schilling commented 4 months ago

Can you explain these points further? I don't know enough about them.

might lead to a timeout from the resolver running locally.

that it might cause problems with certain resolvers.

Why would a resolver running locally time out? Are there other resolvers you're considering or is it the local case? If there are others can you explain those to me?

I don't use docker often enough to know these answers. Any details you can provide will help.

I'm surprised this is an issue running everything locally.

QBH3 commented 4 months ago

Hi Tim

Funny thing is, i am not even using Docker to run Django, i rather use a Python virtualenv.

The Effect is, that every request takes at least 5 (and up to 10) Seconds to complete.

time wget http://localhost:8000/django-url/
--2024-05-28 19:27:51--  http://localhost:8000/django-url/
Resolving localhost (localhost)... 127.0.0.1
Connecting to localhost (localhost)|127.0.0.1|:8000... connected.
HTTP request sent, awaiting response... 200 OK
Length: 15666 (15K) [text/html]
Saving to: ‘index.html’

index.html
100%[======================================================================================================>]  15,30K  --.-KB/s    in 0s

2024-05-28 19:28:01 (804 MB/s) - ‘index.html’ saved [15666/15666]

real    0m10,054s
user    0m0,001s
sys     0m0,004s

Regarding Resolvers that might cause such timeouts for non-existing domains, Ubuntu using systemd-resolved and some unfortunate Interaction with mDNS and local Search List for DNS does this to non-existing domains like host.docker.internal from the code above.

QBH3 commented 4 months ago

Also, if I think about it a bit longer, the code above opens the server far more than intended.

in two ways:

So i really think, that if the user wants such a behaviour they should be able to manually add host.docker.internal to INTERNAL_IPS without negatively effecting users that do not want such an automatic behaviour.

tim-schilling commented 4 months ago

I can't reproduce this problem you're encountering. Can you create a reproducible environment for me?

When I run make example in the toolbar repo and use wget:

λ time wget http://localhost:8000/           
--2024-05-29 06:59:52--  http://localhost:8000/
Resolving localhost (localhost)... 127.0.0.1
Connecting to localhost (localhost)|127.0.0.1|:8000... connected.
HTTP request sent, awaiting response... 200 OK
Length: 14621 (14K) [text/html]
Saving to: ‘index.html’

index.html                                         100%[===============================================================================================================>]  14.28K  --.-KB/s    in 0s      

2024-05-29 06:59:52 (449 MB/s) - ‘index.html’ saved [14621/14621]

wget http://localhost:8000/  0.00s user 0.00s system 2% cpu 0.141 total
tim-schilling commented 4 months ago

I'm good with creating a separate show toolbar callback for docker.

QBH3 commented 4 months ago

Hi Tim,

what one needs for reproducing this failure is an environment that uses a DNS resolver that times out on resolving host.docker.internal

then you will get the server to hang for as long as the timeout of resolving host.docker.internal is ..

I think basicly it should not try to resolve that domain when not running in a docker.

As a workaround i put host.docker.internal in /etc/hosts and got the server to run without flaws.

MarcoGlauser commented 3 months ago

We share the same observation on Ubuntu. Upgrading from 4.3.0 to 4.4.0, with no other changes, request time increased by ~1 second for us. A request that took 100ms with version 4.3.0 now takes 1 second. This tracks very well with the time it takes for curl to return an error

time curl host.docker.internal
curl: (6) Could not resolve host: host.docker.internal

real    0m0.942s
user    0m0.009s
sys 0m0.003s

This from is within a docker container on an Ubuntu host btw.

A quick google search reveals that host.docker.internal is only exposed on OSX and Windows, but not on Linux.

matthiask commented 3 months ago

A first change has already landed addressing this but isn't yet a part of a release. INTERNAL_IPS is now checked before trying to resolve host.docker.internal and that should hopefully fix many of the local issues people are seeing: https://github.com/jazzband/django-debug-toolbar/commit/cf0cc0dfe86e134ea2a0352a4f0833efbcf9f2c4

MarcoGlauser commented 3 months ago

Awesome, https://github.com/jazzband/django-debug-toolbar/commit/cf0cc0dfe86e134ea2a0352a4f0833efbcf9f2c4 will solve our issue, thank you :)

However, there will still be the issue that host.docker.internal cannot be resolved on linux systems, since it's a feature of docker desktop.

heindrickdumdum0217 commented 3 months ago

I created a very simple project using following command. django-admin startapp test_debug_toolbar

And I added just django-debug-toolbar to make test. After add django-debug-toolbar, admin page loading delays around few seconds.

Here are my settings.

DEBUG_TOOLBAR_CONFIG = {
    "DISABLE_PANELS": [
        # 'debug_toolbar.panels.history.HistoryPanel',
        # 'debug_toolbar.panels.versions.VersionsPanel',
        'debug_toolbar.panels.timer.TimerPanel',
        'debug_toolbar.panels.settings.SettingsPanel',
        'debug_toolbar.panels.headers.HeadersPanel',
        'debug_toolbar.panels.request.RequestPanel',
        'debug_toolbar.panels.sql.SQLPanel',
        'debug_toolbar.panels.staticfiles.StaticFilesPanel',
        'debug_toolbar.panels.templates.TemplatesPanel',
        'debug_toolbar.panels.cache.CachePanel',
        'debug_toolbar.panels.signals.SignalsPanel',
        'debug_toolbar.panels.redirects.RedirectsPanel',
        'debug_toolbar.panels.profiling.ProfilingPanel',
    ],
    "SHOW_TEMPLATE_CONTEXT": True,
}

As you can see, I disabled almost panels, but the same problem. Just adding debug-toolbar middleware is causing few seconds delay.

It seems the problem only happens with django-debug-toolbar 4.4.2, after downgrade to 4.3.0, I can't see the problem.

note I'm not using Docker for the test project.

matthiask commented 2 months ago

Is this still an issue? The DNS resolving now only happens after checking INTERNAL_IPS, so I'd hope this isn't an issue anymore in 99% of cases.

heindrickdumdum0217 commented 2 months ago

I tried on Ubuntu 22.04 directly it worked, but when I try on VM it didn't work.

johnthagen commented 2 months ago

It seems the problem only happens with django-debug-toolbar 4.4.2, after downgrade to 4.3.0, I can't see the problem.

@heindrickdumdum0217 The regression was in

The fix for this was

And was released in 4.4.3

So you should try updating to 4.4.3 or later.

I believe this issue can be closed now.

heindrickdumdum0217 commented 2 months ago

@johnthagen Yes, after upgrade, the error gone.

tim-schilling commented 1 month ago

Closing as fixed. Thanks @johnthagen for communicating that.