strange bug: first request after launching the browser is skipped - (pending) request

[josephernest]

Platform: Windows 10 Enterprise, build 19041 ; Python 3.8 ; Bottle v.0.12.19 Tested browsers: Chrome, Edge No internet connection on the computer

Run this app.py in a console:

from bottle import Bottle, TEMPLATE_PATH, template, static_file
app = Bottle("")
TEMPLATE_PATH.append("templates")
@app.route("/pages/<page>")
def page_route(page=None):
    return template(f"{page}.html")
app.run(port=5001)

templates/starting.html

hello

• Then open Edge or Chrome, enter http://127.0.0.1:5001/pages/starting in the URL bar, then enter. Then the circular progress bar is turning, but the request isn't done.
• It is not logged in the Python/bottle console (which usually logs all requests)
• The browser Developer Tools > Network tab shows Status (pending)
• If I refresh the browser by selecting the URL bar and re-do ENTER, then it works, the request is done, and the browser shows "hello".
• Same problem if I launch the browser from command-line: chrome.exe --kiosk http://127.0.0.1:5001/pages/starting, sometimes it works, sometimes this page is not loaded on startup
• This issue never happens when I use python -m http.server, so it might potentially be linked to bottle
• I cannot reproduce the bug on another Windows 7 computer

Do you have any idea?

[defnull]

The development server (based on wsgiref) is single-threaded (to simplify debugging). If there is a request hanging for whatever reason, then no other request can be served at the same time. Perhaps there is a plugin or browser feature that tries to download a second resources while the first is still downloading, but blocks the first download while waiting for the second request to finish. That would be a deadlock. You won't see that in the logs until the browser gives up, because only finished (or aborted) requests are logged.

Try a different (multi-threaded) WSGI server and the problem should go away. If you want to find out what exactly causes the problem, you probably have to look at the actual network traffic.

[josephernest]

@defnull It seems very hard to debug this problem, I spent some time on this - is there a mode in which I can enable very very verbose logging, so that I can detect if there is a hanging request?

If there is a request hanging for whatever reason, then no other request can be served at the same time. Perhaps there is a plugin or browser feature that tries to download a second resources while the first is still downloading

In all my tests, every time, I close the browser, I stop the Python server and I make sure every python.exe and Chrome is killed. Then I start the Python server (nothing else is running on the computer), and I launch chrome.exe http://127.0.0.1:5001/pages/starting, and randomly maybe 50% of the time, sometimes it doesn't load.

PS: I tried with app.run(port=5001, threaded=True), which finally displays Bottle ... starting up using WSGIRefServer(threaded=True)... and it's the same.

[j9brown]

I am observing a similar issue with a "(pending)" request that doesn't get logged and doesn't complete until much later with a Bottle server running on Linux and recent Chrome on Mac OS.

tcpdump shows the HTTP request packet being sent by the browser to the Bottle server and ACK'd. However Bottle doesn't seem to notice that it has a request pending: it does not log the request and it does not send any response.

Subsequently upon receiving another HTTP request, Bottle will finally notice that it already had one pending and it processes both requests immediately.

I suspect that there's an issue in Bottle's event loop that's causing it to fail to notice that there's data available to read on the socket.

In my tests, I can reproduce this very reliably by issuing POST requests from the browser by clicking on a button a few times. The requests will be processed normally several times, then one stalls.

[josephernest]

@j9brown Did you find a temporary fix for this problem? (Which Chrome version do you use?)

Subsequently upon receiving another HTTP request, Bottle will finally notice that it already had one pending and it processes both requests immediately.

Yes, I have the exact same situation.

[j9brown]

Not yet. Digging deeper, the problem may be in the wsgiref HTTP server that bottle uses by default. I'm going to try some different server implementations to see if the issue goes away.

[j9brown]

Ok, I switched to Waitress (an arbitrary choice) and the problem seems to be gone.

pip3 install waitress

bottle.run(host='0.0.0.0', port=8081, server="waitress")

[josephernest]

@j9brown Do you think there is a way to set up WSGIRefServer in a way that it works? Since it's a project which runs on localhost and doesn't need a complex server, I wanted to keep things simple and the single bottle.py file was pretty cool :) It would be nice to avoid having to use another server like waitress (I want to keep the lowest number of dependencies). Are there some configuration settings for WSGIRefServer?

[j9brown]

I have no idea. I stumbled across a mention of a different bug in WSGIRefServer which led me to try a different server. https://github.com/Pylons/webob/issues/233 (note that this might not be the cause of what we've seen here, just evidence that bugs might exist)

I suspect the only way to fix this for real is an upstream patch but I haven't actually looked into what might be involved.

FWIW, I'm using bottle.py on some little Raspberry Pi projects. I used to copy the python binary into my repository but today I switched to installing it via pip3 since I was observing weird behavior and wanted to try upgrading my version. Once I'd done that, installing another small package for a better web server was pretty painless for me.

[defnull]

Bottle does not handle HTTP at all, that's the job of the WSGI server. wsgiref (the default development server) is not perfect. It's just the default because it is part of the python standard library and does not require any external dependencies, and because applications are easier to debug (with an actual debugger like pdb) if requests do not run in parallel. For any real world usage (or if you see problems like these) I'd strongly suggest switching to a more sophisticated WSGI server.

[defnull]

I'm still curious what exactly goes wrong in wsgiref and if this can be fixed (on pythons side, not in bottle).

[j9brown]

Yeah, it's definitely strange behavior for a reference implementation.

@defnull I think it might be worth documenting that the default wsgiref may have some issues and recommending that users install a different one.

Also, I suggest expanding the documentation for the server argument of bottle.run to list the supported web servers with links to them. I had to read the source code to find the server_names referenced in the documentation and do some digging to figure out how to set things up.

[defnull]

It is documented. The wsgiref server is called a 'development server' throughout documentation and the deployment section offers many alternatives with reasons why to not use wsgiref in production: https://bottlepy.org/docs/dev/deployment.html

Your bug is not expected. It should be fine to use wsgiref for applications that do not care about performance or parallel requests. But that's a bug in wsgiref, not bottle, so there is not much we can do about that besides reporting the issue to the python issue tracker.

[josephernest]

Can we use https://docs.python.org/3/library/http.server.html to avoid external third-party pip install ... dependencies? This bug doesn't happen when using python -m http.server (which serves file in a directory, I don't know if it can be used as a HTTP server to serve more general requests).

[j9brown]

@defnull Nice! I didn't notice that section of the documentation. Looks great!

For my use-case, a simple single-threaded server was fine so it hadn't occurred to me to make any changes until now.

[defnull]

Bottle is a WSGI framework, it needs a server implementation stat speaks WSGI and the only WSGI server in the python standard library is wsgiref. Under the hood, wsgiref is based on http.server (or at least based on the same HTTP implementation) so both should see similar problems.

[josephernest]

@defnull Can we more or less use http.server directly in bottle instead of wsgiref? Or the former doesn't speak WSGI?

[defnull]

http.server does not speak WSGI, that is what wsgiref is for.

[josephernest]

@defnull would you know how to report this bug appropriately in upstream Python repo? I'm not very familiar with Bottle internals, do you think @j9brown we could write a minimal example using WSGIRef only so that the problem is easily reproducible? Maybe using this:

In my tests, I can reproduce this very reliably by issuing POST requests from the browser by clicking on a button a few times. The requests will be processed normally several times, then one stalls.

[j9brown]

To be honest, I’m not that motivated to try to chase this down.

I took a quick look at the wsgiref implementation and indeed it relies on http.server. It’s all pretty simple. The request handling code just calls readline() in a loop to read the headers and parses them with minimal error checking.

Given the intermittent nature of the issue, it wouldn’t surprise me if some I/O edge case wasn’t being handled correctly somewhere such as a short read or EINTR. It could also come down to the single-threaded synchronous nature of the implementation getting gummed up waiting on one socket while the next request arrives on a different socket. Who knows? It feels like a rabbit hole.

[josephernest]

@j9brown I'm interested to investigate a little bit. Probably 95% of people starting with Bottle start with WSGIRef, before moving to another server (I made up this figure, but I think it's probably the case, what do you think @defnull?). So if it doesn't work reliably with WSGIRef, some people might think Bottle would be the cause and move to another library...

In my tests, I can reproduce this very reliably by issuing POST requests from the browser by clicking on a button a few times. The requests will be processed normally several times, then one stalls.

Can you share your test code (sometimes a little detail makes all the difference in such debugging situations), I will try to reproduce it on my machine.

Strange thing: it is only present on Windows 10 + Chromium v.103, but I cannot reproduce on Windows 7 + Chromium v.103.

[josephernest]

Could be linked:

https://stackoverflow.com/questions/51579814/serverless-wsgi-local-server-running-slow

Chrome Preconnect Breaks Singly Threaded Servers

https://github.com/pallets/flask/issues/2169 https://github.com/corydolphin/flask-cors/issues/147 https://github.com/benoitc/gunicorn/issues/1284

This is coherent with @defnull's comments here.

But then, if this is the core reason of the problem, wouldn't app.run(port=5001, threaded=True) which finally does starting up using WSGIRefServer(threaded=True)... solve the problem? In my case it didn't. Update: it's normal: even if doing app.run(threaded=True) and even if WSGIRefServer(threaded=True) is displayed, it seems to not be threaded: do a dummy request that time.sleep(5) before returning the response, and then do another request, you notice the 2nd request has to wait for the first to finish. TL;DR: even if WSGIRefServer(threaded=True) is displayed, it's still not threaded.

[defnull]

This Chrome Preconnect "feature" would perfectly explain the observed issue.

[defnull]

run() passes all parameters it does not interpret itself to the server adapter, and that may or may not act on these parameters. The current implementation of WSGIRefServer does not handle the threaded option. Not sure where you got the idea it does.

[josephernest]

Ok I will try to disable Preconnect / Preload and see if it solves it.

Not sure where you got the idea it does.

It came from the notice Bottle v0.12.19 server starting up (using WSGIRefServer(threaded=True)).... Since it was written threaded=True I thought this simple server implemented a (very basic) threaded mode. But now after looking in the source, I see it's not the case (but I didn't know before looking at the source).

[defnull]

Yes the string representation of the ServerAdapter class may be misleading, as it simply prints all options, no matter if they have an effect or not. Fortunately looking at the source is always an option with bottle. WSGIRefServer is just 31 lines.

[josephernest]

Yes that's why I love Bottle and the fact it's a single file @defnull :) (please keep this single-file aspect forever :))

[josephernest]

Bug report on Chromium: https://bugs.chromium.org/p/chromium/issues/detail?id=1349353

Issue now 100% solved @defnull: I confirm it's the Chrome Preload "feature".

Solution:

As a work around, you can turn off the preconnection feature in chrome. Go to Settings > Advanced > Privacy and security and turn off Use a prediction service to load pages more quickly. This is now in Settings > Cookies and other site data > Preload pages for faster browsing and searching in more recent versions of Chrome.